leaking eventcore driver because there are still active handles #2245
Comments
|
Looks like you just forgot about explicitly closing any open websockets when the server process is being terminated, hence 'there are still active handles'. For a simple test like this, that may probably be ignored. |
|
this actually happens even without any connections @thaven. also, with 0.8.5 beta the app does not even start. |
|
This is reproducible on my system (and in my project). I see this behavior in the following environments: EDIT: This is particularly annoying because the trailing sockets (which apparently do exist) prevent whatever application is/was running from restarting (it fails to bind). |
|
Yep, seeing it with: module app;
import vibe.http.router;
import vibe.web.rest;
shared static this ()
{
auto router = new URLRouter();
auto settings = new HTTPServerSettings("0.0.0.0");
settings.port = 4245;
router.registerRestInterface(new Server1());
listenHTTP(settings, router);
}
@safe:
interface API1 { string getGreeting(); }
class Server1 : API1 { string getGreeting() { return "API1"; } }As well... |
|
I'm getting that error message with Redis as well on vibe 0.8.4 |
|
Okay, so this is because import vibe.d;
class CheckTODO {
@path("/health")
void health(HTTPServerRequest req, HTTPServerResponse res) {
res.writeBody("ok");
}
}
void main() {
auto router = new URLRouter;
router.registerWebInterface(new CheckTODO);
auto settings = new HTTPServerSettings;
settings.port = 8080;
listenHTTP(settings, router);
// runApplication();
}However, if I uncomment |
|
I'm experiencing this with vibe-d's provided entrypoint, which should just run |
|
Ah, I missed that, sorry. |
|
You have to start the eventloop either way. This is the server not cleaning
up before exit from what I understand. Maybe it has something to do with a
lingering route. Honestly not sure. Do you guys know if this results in a
non 0 exit code? If so it's bad for things like docker container
orcestration, which I use.
…On Mon, Jun 24, 2019, 2:21 PM Jude Pereira ***@***.***> wrote:
Ah, I missed that, sorry.
—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub
<#2245?email_source=notifications&email_token=AHF3S727PEIIDBRWK53YQ4DP4ENFDA5CNFSM4GMIDZ52YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODYN6LHA#issuecomment-505144732>,
or mute the thread
<https://github.com/notifications/unsubscribe-auth/AHF3S74FKFXFSCX4RWHZJELP4ENFDANCNFSM4GMIDZ5Q>
.
|
|
Exit code is still 0 in my experience. |
|
In that case I'm not so worried. The only thing I'm worried (a little)
about it that routes are still processing jobs at exit. Makes 0 downtime
deploys not entirely possible. However, from the looks of things, the fds
were not cleaned up properly, that could be all. I had the same error
message with vibed-redis and had to switch to tinyredis to solve it.
…On Tue, Jun 25, 2019 at 10:15 PM Chloe Kudryavtsev ***@***.***> wrote:
Exit code is still 0 in my experience.
—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub
<#2245?email_source=notifications&email_token=AHF3S77C5ZNHD6G6EJVGI7TP4LNLNA5CNFSM4GMIDZ52YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODYSGBGY#issuecomment-505700507>,
or mute the thread
<https://github.com/notifications/unsubscribe-auth/AHF3S73ZPBNLFPDITAYR7OTP4LNLNANCNFSM4GMIDZ5Q>
.
--
*Clinton Skakun*
*Founder and CEO*
Dedupely Software, Inc. | Dedupe.ly <https://dedupe.ly/>
*HQ:*
11871 Horseshoe Way #1103,
Richmond,
BC V7A 5H5,
Canada
*Latam:*
333c Interior
Calle 12 x 1A y calle cerrada,
Col. Vista Alegre Norte
97130 Mérida, Yucatán
|
|
I'm still having issues with this and strangely it appears that the port is not being let go of (not sure if this makes sense). Because on restart it crashes to due to the port being in use. Maybe 'leaking eventcore' has something to do with the http listener not closing? |
|
The port reuse issue will be fixed with vibe-core 1.7.0 (already available in the latest beta), the default for A generic, built-in way to wait for all incoming HTTP requests to complete is still missing, but |
Thanks this is what I needed to hear. It will be an easy fix once we have 1.7.0 in production. Can I use |
|
Hmm, this actually appears to have fixed the issue: I updated to 1.7.0 beta2 (probably does not change much in this leaking case). Because my app uses it's own main and I call As per @s-ludwig 's instruction, I did this: This was what I got before: This is what I get now: So it looks like that was the problem. Event loop exit doesn't seem to close the listening socket created in listenHTTP. |
|
I'm having a similar issue. I've just now tried to make sure all sockets are closed so I don't get this error message. I believe I'm handling all the database connections, and I'm on 1.7.0 of vibe-core. When I look at the trace output, the sockets that are left are the streamSockets used by the web server to handle incoming requests. Looking at the code, it appears they should be closed, but there's no trace to say a socket is closed. |
|
Just to clarify, my messages say |
|
I still get this as well, but I'm using a number of different services like phobos tcp sockets, postgres and beanstalkd. Any one of these could be contributing. However, I've noticed I get it less running the stopListening at the end. Honestly I don't know enough about Vibe.d under the hood to really make educated guesses on this. |
|
The underlying issue of WHY this happens is that the event driver is cleaning up synchronously, but items that will be cleaned up by the GC are still holding resources. Since the GC is the last thing that cleans up, the event driver has to leak its resources to avoid segfaults. Before these messages you'd get a segfault every close. But I would expect the core vibe-d fibers to properly release sockets when they are done. |
|
More info: it's the redis session store that is not closing. I'm "cheating" by using tupleof so I can close the driver sockets, but they still leak (I'm using instrumented code that prints out when sockets are closed). Will continue to investigate, I'm hoping if I fix this problem, the messages go away. Note that if I close the app while there are still keepalive sockets open, those will leak. I'd like to see those go away too at shutdown, or at least have a way to wait for them to close. But if you do wait for the timeout, they don't leak. |
|
OK, FINALLY! I figured out why this is happening. The redis session store doesn't provide a way to release unused connections, so as I said, I was cheating and using tupleof to get the ConnectionPool out of the RedisClient. Then I was calling The solution here is to expose the |
|
This is redis-specific though. So the simple programs shown above exhibit a different issue ? |
|
So the examples above seem to come from not closing down the listening socket (which it seems like folks have already fixed). But in general, ANY class-based thing that holds onto a descriptor may leak the driver. The only way to fix is to provide cleanup mechanisms that can be called on program termination, and to have them called. Aside from the redis issue, I need to also update mysql-native so it has a way to do this. Because it seems most of these wrappers hide a private What WOULD be nice is if the call leaking the driver would identify the way that descriptor was used. For example, if it's a file, say "last used to open /x/y/z" or if it's a socket, "last used as a TCP connection to X.X.X.X:Y", to help narrow down where it's leaking from. As with most leaks, it's easy to tell something has leaked, but really difficult to tell where it leaked from. Having those clues can save hours of work (as it did take me hours to instrument everything to find the right place it was opened). Maybe an eventcore option to store the appropriate data for describing the source of the leak. I also just realized, the messages are all being printed twice. Not sure why that is. |
|
Added a PR for fixing the redis issue. |
|
I just experienced this with the "Hello World!" example. This time I'm playing with Vibe.d on FreeBSD (12.1). I'm pretty sure I ran into it many months ago as well, that time when playing with Vibe.d on Gentoo Linux. That was likely also in the "Hello World!" example. To reproduce the problem, in brief:
Thankfully, on this system and with this config (FreeBSD 12.1; w/ VibeHighEventPriority if it matters) the bug/warning doesn't prevent subsequent runs of the test executable. I can ctrl-C and rerun immediately over and over again to my heart's content. It can even restart effectively instantly after I visit the "Hello World!" webpage. In my case, It just looks disturbing, because of the warning message. The source/app.d contents I had at the start, with bug present as described above, looked like this: import vibe.vibe;
void main()
{
auto settings = new HTTPServerSettings;
settings.port = 8080;
settings.bindAddresses = ["::1", "127.0.0.1"];
listenHTTP(settings, &hello);
logInfo("Please open http://127.0.0.1:8080/ in your browser.");
runApplication();
}
void hello(HTTPServerRequest req, HTTPServerResponse res)
{
res.writeBody("Hello, World!");
}I made it go away by modifying it according to @s-ludwig 's suggestion and @dedupely 's example earlier in this thread: import vibe.vibe;
void main()
{
auto settings = new HTTPServerSettings;
settings.port = 8080;
settings.bindAddresses = ["::1", "127.0.0.1"];
auto listener = listenHTTP(settings, &hello);
scope(exit)
listener.stopListening();
logInfo("Please open http://127.0.0.1:8080/ in your browser.");
runApplication();
}
void hello(HTTPServerRequest req, HTTPServerResponse res)
{
res.writeBody("Hello, World!");
}Note the With that, the output becomes: Yay! No more leaking eventcore drivers. I suspect that this particular manifestation can be fixed with documentation and example changes. The idiomatic code I see in the example above and on the documentation webpage seems to follow the same pattern (omitting the listener assignment statement and later .stopListening() call), and this pattern is requisite for this problem to happen. I suggest using something like the modified example above as the default example. Then it will not only copy, paste, and run without warning messages (and possible blocked sockets), but it shows learners that the object returned from listenHTTP holds network resources (it's all in the "stopListening" name) as well as how to release those resources. I'd try to provide a PR, but I already looked for the source of that app.d "Hello World!" example and couldn't find it quickly. I hope it at least helps to know that this can happen in basic examples. Thank you all. |
|
The underlying issue here is that one does not get detailed information about what handles are leaking, and when they were opened. It would be huge to be able to identify what the handles were doing. FD 8 and FD 9 is useless information. streamListen is useful, but not entirely descriptive. I'd like to see at a minimum all the information that vibe-core knows about it (i.e. if it's a socket, what type (TCP/UDP), IP address/port it's connected to, if possible when it was opened). It would be even better to get a stack trace from the place the last time the socket was used (enabled only with a certain flag of course). I think this should be doable. The root cause of all these is -- you didn't release a resource. But finding out which resource and why it was opened is very difficult from the messages given. I also agree the default vibe-d server should clean up itself properly. |
|
I... totally agree and also really like good error messages. I hope I didn't distract from that. I just wanted to provide an easy (I hope) solution for an adoption pitfall that arises as one consequence of the resource management and error reporting issues. By that logic, it seems that this could probably spawn a few separate issues, in addition to the redis one that you handled: fix idioms in documentation, more specific+useful error messages, error messages are printed twice, less error-prone resource management (scope or ref-count non-memory resources by default?), and maybe more. I worry that I would do a poor job of writing those because I lack specifics and am not very familiar with vibe.d (yet). |
|
In my testing, |
|
Hi all. thanks for the helpful suggestions. Full disclosure, I'm not that good at coding. intermediate at best. What i did notice on my setup though (Catalina, fresh D install, new vibe-d template project) is that NO MATTER WHAT I DO - scope(exit) or otherwise - i can only rerun the vibe-d application after refreshing my web browser one time. Steps to reproduce:
With scope(exit) listener.stopListening() I get the "Stopped listening" log ONLY after ONE browser refresh following Ctrl-C. Without scope(exit) i do not receive that log message at all. I don't know much about whats going on architecturally but it seems that a remnant of the app is sitting somewhere after Ctrl-C is pressed and remains until at least one request is made for/of that remnant. I'm not sure if any of this is helpful as I currently only speak noob, but it reproduces every time... |
|
I also came across this problem and wrote about it on DLang forums [1]. This is the toy example [2] I've been working on to test. [1] https://forum.dlang.org/post/finhhdbacjeybbjohgxv@forum.dlang.org |
|
Still happening, although now vibe-core is a bit more verbose: |
|
Whoa, are those messages accurate? Like with a switch I can see a stack trace of where a leaked handle was allocated? That's exactly what needs to happen to find these issues! |
|
Hey Steve. I have had similar errors before. Any tools you suggest to get the stack trace? Happy to give it a try. |
|
Just look at the message above. it says what to do to get a trace (define |
|
@schveiguy @s-ludwig This is still an issue. I was able to get a stack trace using the debug flag. Platform:macOS 11.4 Big Sur Steps to reproduce:
OutputThen reload the page in the browser and this is printed to the console. |
|
The zombie issue has been fixed yesterday: #2596 |
|
@JackStouffer : We were also discussing this in here. |
|
Hm... that's not my experience though. When I kill the app, it shuts down, it doesn't still handle any requests. There was a bug a while ago that had this happening on Linux, see vibe-d/vibe-core#205. The leaking of resources I don't think is anything that vibe or vibe-core can deal with, because it's the application that isn't properly cleaning itself up. But what is important is the stack trace showing where the leaked handle was allocated. Thanks for the printout, @JackStouffer, It looks a little rough, but seems to get the job done (kinda funny seeing the DefaultTraceInfo ctor always at the top). |
|
@schveiguy Well if there's anything I can add to my code as a work around to clean up the server from a Ctrl-C, please let me know. @Geod24 I've updated to the latest version of vibe-core and I'm still getting the same issue. Used the same testing steps as before. dub.json: {
"authors": [
"Jack Stouffer"
],
"copyright": "Copyright © 2021, Jack Stouffer",
"debugVersions": [
"EventCoreLeakTrace"
],
"dependencies": {
"vibe-core": "~>1.19.0",
"vibe-d-postgresql": "~>3.0.1",
"vibe-d:crypto": "~>0.9.3",
"vibe-d:data": "~>0.9.3",
"vibe-d:inet": "~>0.9.3",
"vibe-d:stream": "~>0.9.3",
"vibe-d:tls": "~>0.9.3",
"vibe-d:web": "~>0.9.3"
},
"description": "ecommerce",
"license": "proprietary",
"name": "ecommerce"
}app.d import vibe.core.core;
import vibe.http.router;
import vibe.http.server;
void index(HTTPServerRequest req, HTTPServerResponse res)
{
res.render!("index.dt", req);
}
void main()
{
auto router = new URLRouter;
router.get("/", &index);
auto settings = new HTTPServerSettings;
settings.port = 8080;
listenHTTP(settings, router);
runApplication();
}Stack trace |
|
@JackStouffer As noted near the top of this thread, you need to clean up the listener: #2245 (comment) However, I don't think it should still keep the process running if you didn't do this. I am not experiencing that, but I'm also cleaning up my listener, so not sure. |
|
Still getting the same issue. Here's my updated app.d import vibe.core.core;
import vibe.http.router;
import vibe.http.server;
void index(HTTPServerRequest req, HTTPServerResponse res)
{
res.render!("index.dt", req);
}
void main()
{
auto router = new URLRouter;
router.get("/", &index);
auto settings = new HTTPServerSettings;
settings.bindAddresses = ["127.0.0.1"];
settings.port = 8080;
auto listener = listenHTTP(settings, router);
runApplication();
// cleans up event loop
listener.stopListening();
} |
|
I'm also getting problems with descriptors. |
|
This problem shows up any time I store a Reproducer: import vibe.core.core;
import vibe.core.net;
class Leaky
{
UDPConnection conn;
this(UDPConnection conn) { this.conn = conn; }
}
void main()
{
auto conn = listenUDP(1234); // -debug=EventCoreLeakTrace flags this line
scope(exit) conn.close();
auto leaky = new Leaky(conn);
runTask({ exitEventLoop(); });
runEventLoop();
}Warnings at exit (normal build)Warnings at exit (EventCoreLeakTrace build)Workarounds I've found so far:
However, having to clutter function signatures with repetitive arguments, give up classes, forbid The fact that Surely there must be a way for a Vibe socket handle to live in class without restrictions or complaints, just as a file descriptor can. Maybe Tested with vibe-core 2.8.2 on linux. |
|
I'm still getting this issue. Right now it's mostly because of redis. I went back to vibe.d redis again. Once again the problem perisists. For me the stack trace points to RedisReply and then finally the Streaming library in vibe.d. I'm don't know the inner workings of how this happens, but if we can catch and count these FDs, why can't they be cleaned up on shutdown? Is there some type of place of return where they're no longer touchable? This seems to happen a lot in runTask but it also happens in the mean thread (if I get it correctly). I've tried all of the above and nothing seems to work. The reason I think this is an issue long term is that I'm not sure if it's indefinitely binding FDs and eating them up one at the time in the environment. Like can we eventually run out of descriptors at some point? Anyways, aside from that which may actually be a problem, my error logs in k8s are really cluttered because I can't turn this message off either unless I completely disable warnings which is not good for reporting. |
|
@dedupely did you try calling this on your db? https://vibed.org/api/vibe.db.redis.redis/RedisClient.releaseUnusedConnections |
|
@schveiguy Found it! I was calling that function above and then later the redis.quit(); function which was actually opening a new connection and then causing the leak. I used only releaseUnusedConnections and that works perfectly. |
hello everyone
i need to build a websocket server that needs to talk to cups. i've got that part sorted out. i've tried to give the websocket example a try.
vibe.d version 0.8.4: compiles well however when i quit the server, i got this message:
leaking eventcore driver because there are still active handlesvibe.d version 0.8.5.beta: does not even run, it exits with the same error.
os: macOS high sierra (10.13.6)
kernel: Darwin Kernel Version 17.7.0: Thu Jun 21 22:53:14 PDT 2018; root:xnu-4570.71.2~1/RELEASE_X86_64 x86_64
dmd: DMD64 D Compiler v2.083.1
ldc: LDC - the LLVM D compiler (1.7.0):
here's the sample code:
The text was updated successfully, but these errors were encountered: