Re: [capnproto] Warnings "EventLoop destroyed with events still in the queue. Memory leak?"

['Kenton Varda' via Cap'n Proto]

Yes, it's normal. I agree it's kind of spammy but I haven't figured out
what to do about it.

On Tue, Jun 7, 2022 at 7:25 PM Jens Alfke  wrote:

>
>
> On Jun 7, 2022, at 3:07 PM, Kenton Varda  wrote:
>
> Info-level logs are generally meant to be enabled only for debugging, so
> the idea here is you normally shouldn't see this log.
>
>
> But I *am* debugging :) I’m debugging my code, using KJ logging. So I do
> see this somewhat scary-looking message mixed in with my own logs.
>
> All exceptions that are transmitted over RPC are info-logged
>
>
> So it's normal for this exception to be created & transmitted when a
> client connection closes? If so I’ll just ignore it from now on.
>
> —Jens
>
>

-- 
You received this message because you are subscribed to the Google Groups 
"Cap'n Proto" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to capnproto+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/capnproto/CAJouXQ%3DVo9QhMAJ_cN1nQ1M-q%2BXZr-tToFooS6krF8Yx%3DLQWiQ%40mail.gmail.com.

Re: [capnproto] Warnings "EventLoop destroyed with events still in the queue. Memory leak?"

[Jens Alfke]

> On Jun 7, 2022, at 3:07 PM, Kenton Varda  wrote:
> 
> Info-level logs are generally meant to be enabled only for debugging, so the 
> idea here is you normally shouldn't see this log.

But I am debugging :) I’m debugging my code, using KJ logging. So I do see this 
somewhat scary-looking message mixed in with my own logs.

> All exceptions that are transmitted over RPC are info-logged 

So it's normal for this exception to be created & transmitted when a client 
connection closes? If so I’ll just ignore it from now on.

—Jens

-- 
You received this message because you are subscribed to the Google Groups 
"Cap'n Proto" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to capnproto+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/capnproto/9B4D459A-AC88-40F9-86C6-37A2757DD63E%40mooseyard.com.

Re: [capnproto] Warnings "EventLoop destroyed with events still in the queue. Memory leak?"

['Kenton Varda' via Cap'n Proto]

Hi Jens,

Info-level logs are generally meant to be enabled only for debugging, so
the idea here is you normally shouldn't see this log. All exceptions that
are transmitted over RPC are info-logged but normally you would only want
to log them in production if some actual operation you care about fails
with this exception.

-Kenton

On Tue, Jun 7, 2022 at 5:03 PM Jens Alfke  wrote:

>
>
> On Jun 7, 2022, at 9:53 AM, 'Kenton Varda' via Cap'n Proto <
> capnproto@googlegroups.com> wrote:
>
> Ideally, you should set things up so that when the stack unwinds, all
> Promise objects are destroyed before the EventLoop is destroyed.
>
>
> Thanks! I actually figured this out shortly after posting, but forgot to
> send a follow-up. I had to inspect some classes' member declarations
> carefully to find the two that were in the wrong order; swapping them fixed
> it.
>
> But maybe you can help me with a less-annoying warning that I’m still
> getting. When either the client or the server connection closes, I always
> get an Info-level log:
>
> *returning failure over rpc; exception = capnp/rpc.c++:3107: failed:
> RpcSystem was destroyed.*
>
> It appears harmless, and no exception is actually thrown, but I’d rather
> not be logging this. Any idea what I might still be doing wrong?
>
> —Jens
>

-- 
You received this message because you are subscribed to the Google Groups 
"Cap'n Proto" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to capnproto+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/capnproto/CAJouXQm%3DGZtuX5Jn_QYS1bj2LRJiqtBvFp_som0EkggbYvk0eA%40mail.gmail.com.

Re: [capnproto] Warnings "EventLoop destroyed with events still in the queue. Memory leak?"

[Jens Alfke]

> On Jun 7, 2022, at 9:53 AM, 'Kenton Varda' via Cap'n Proto 
>  wrote:
> 
> Ideally, you should set things up so that when the stack unwinds, all Promise 
> objects are destroyed before the EventLoop is destroyed. 

Thanks! I actually figured this out shortly after posting, but forgot to send a 
follow-up. I had to inspect some classes' member declarations carefully to find 
the two that were in the wrong order; swapping them fixed it.

But maybe you can help me with a less-annoying warning that I’m still getting. 
When either the client or the server connection closes, I always get an 
Info-level log:

returning failure over rpc; exception = capnp/rpc.c++:3107: failed: RpcSystem 
was destroyed.

It appears harmless, and no exception is actually thrown, but I’d rather not be 
logging this. Any idea what I might still be doing wrong?

—Jens

-- 
You received this message because you are subscribed to the Google Groups 
"Cap'n Proto" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to capnproto+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/capnproto/23F7A5D0-8538-4C16-8E55-57FBC207BA70%40mooseyard.com.

Re: [capnproto] Warnings "EventLoop destroyed with events still in the queue. Memory leak?"

['Kenton Varda' via Cap'n Proto]

Hi Jens,

Sorry for the slow reply.

This error indicates that the KJ EventLoop (which is part of the objects
returned by kj::setupAsyncIo()) was destroyed while some kj::Promise
objects still existed.

Ideally, you should set things up so that when the stack unwinds, all
Promise objects are destroyed before the EventLoop is destroyed.
Alternatively, make sure to catch all exceptions at the top level such that
the EventLoop is never destroyed.

-Kenton

On Mon, May 23, 2022 at 6:15 PM Jens Alfke  wrote:

> I’m in the midst of improving the error handling in my code, but there’s a
> warning logged by KJ that I can’t figure out. I’d appreciate any advice or
> insight.
>
> It happens when my client code fails to connect because server-side auth
> fails, so it gets an abrupt "Connection reset by peer” error that’s thrown
> from the first Promise::wait() call. That exception causes my client object
> to get destructed, and during its destructor the warning gets logged (with
> a bunch of backtrace.)
>
> The message as logged from my onRecoverableException handler looks like:
>
> expected head == nullptr [10bf07390 == nullptr]; EventLoop destroyed with
> events still in the queue.  Memory leak?; head->traceEvent() = 10152fc4c
> 101548a28
> kj::_::ImmediatePromiseNode
> >::get(kj::_::ExceptionOrValue&) (in myapp) + 0: returning here
>
> The call stack is pretty long, so I’ve tried to clean it up a bit. “myapp”
> is app code. “snej::shs” is my implementation of the SecretHandshake
> secure-socket protocol, including CapnP glue code adapted from ez-rpc.c++.
>
> myapp::KJExceptionCallback::onRecoverableException() at Logging.cc:80
> :28
> kj::_::Debug::Fault::~Fault() + 172
> kj::EventLoop::~EventLoop() + 432
> kj::_::HeapDisposer kj::Disposer::Dispose_::dispose() at
> memory.h:522:14
> void kj::Disposer::dispose() const at
> memory.h:534:3
> kj::Own::dispose() at memory.h:278:17
> kj::Own::~Own() at memory.h:204:28
> kj::Own::~Own() at memory.h:204:26
> kj::AsyncIoContext::~AsyncIoContext() at async-io.h:876:8
> kj::AsyncIoContext::~AsyncIoContext() at async-io.h:876:8
> snej::shs::SecretRPCContext::~SecretRPCContext() at SecretRPC.cc:56
> :9
> snej::shs::SecretRPCContext::~SecretRPCContext() at SecretRPC.cc:50
> :45
> snej::shs::SecretRPCContext::~SecretRPCContext() at SecretRPC.cc:50
> :45
> kj::Disposer::Dispose_::dispose() at
> memory.h:522:14
> void kj::Disposer::dispose() const at
> memory.h:534:3
> kj::Own::dispose() at memory.h:278:17
> kj::Own::~Own() at memory.h:204:28
> kj::Own::~Own() at memory.h:204:26
> snej::shs::SecretRPCClient::Impl::~Impl() at SecretRPC.cc:283
> :29
> snej::shs::SecretRPCClient::Impl::~Impl() at SecretRPC.cc:283
> :29
> kj::_::HeapDisposer::disposeImpl() const
> at memory.h:433:60
> kj::Disposer::Dispose_::dispose()
> at memory.h:528:14
> void kj::Disposer::dispose() const at
> memory.h:534:3
> kj::Own::dispose() at memory.h:278:17
> kj::Own::~Own() at memory.h:204:28
> kj::Own::~Own() at memory.h:204:26
> snej::shs::SecretRPCClient::~SecretRPCClient() at SecretRPC.cc:383
> :59
> snej::shs::SecretRPCClient::~SecretRPCClient() at SecretRPC.cc:383
> :57
> kj::_::HeapDisposer::disposeImpl() const at
> memory.h:433:60
> kj::Disposer::Dispose_::dispose() at
> memory.h:528:14
> void kj::Disposer::dispose() const at
> memory.h:534:3
> kj::Own::dispose() at memory.h:278:17
> kj::Own::~Own() at memory.h:204:28
> kj::Own::~Own() at memory.h:204:26
> myapp::net::Client::ConnectionImpl::~ConnectionImpl() at Client.cc:281
> :19
> myapp::net::Client::ConnectionImpl::~ConnectionImpl() at Client.cc:281
> :19
> myapp::net::Client::ConnectionImpl::~ConnectionImpl() at Client.cc:281
> :19
> std::__1::default_delete::operator() const at
> unique_ptr.h:57:5
> std::__1::unique_ptr std::__1::default_delete >::reset() at
> unique_ptr.h:318:7
> std::__1::unique_ptr std::__1::default_delete >::~unique_ptr() at
> unique_ptr.h:272:19
> std::__1::unique_ptr std::__1::default_delete >::~unique_ptr() at
> unique_ptr.h:272:17
> myapp::net::Client::~Client() at Client.cc:314 :21
> myapp::net::Client::~Client() at Client.cc:314 :21
> myapp::SyncTask::_run() at SyncTask.cc:166 :5
> myapp::SyncTask::run() const at SyncTask.cc:82 :9
> kj::_::RunnableImpl kj::_::runCatchingExceptions() + 36
> kj::Maybe kj::runCatchingExceptions at exception.h:332:10
> myapp::SyncTask::run() at SyncTask.cc:82 :9
> SyncCommand::runSubcommand() at ClientMain.cc:842
> :24
> InteractiveTool::runSubcommand() at InteractiveTool.cc:72
> :29
> myappClient::run() at ClientMain.cc:178 :13
> 

[capnproto] Warnings "EventLoop destroyed with events still in the queue. Memory leak?"

[Jens Alfke]

I’m in the midst of improving the error handling in my code, but there’s a 
warning logged by KJ that I can’t figure out. I’d appreciate any advice or 
insight.

It happens when my client code fails to connect because server-side auth fails, 
so it gets an abrupt "Connection reset by peer” error that’s thrown from the 
first Promise::wait() call. That exception causes my client object to get 
destructed, and during its destructor the warning gets logged (with a bunch of 
backtrace.)

The message as logged from my onRecoverableException handler looks like:

expected head == nullptr [10bf07390 == nullptr]; EventLoop destroyed with 
events still in the queue.  Memory leak?; head->traceEvent() = 10152fc4c 
101548a28
kj::_::ImmediatePromiseNode 
>::get(kj::_::ExceptionOrValue&) (in myapp) + 0: returning here

The call stack is pretty long, so I’ve tried to clean it up a bit. “myapp” is 
app code. “snej::shs” is my implementation of the SecretHandshake secure-socket 
protocol, including CapnP glue code adapted from ez-rpc.c++.

myapp::KJExceptionCallback::onRecoverableException() at Logging.cc:80:28
kj::_::Debug::Fault::~Fault() + 172
kj::EventLoop::~EventLoop() + 432
kj::_::HeapDisposer::dispose() at 
memory.h:522:14
void kj::Disposer::dispose() const at 
memory.h:534:3
kj::Own::dispose() at memory.h:278:17
kj::Own::~Own() at memory.h:204:28
kj::Own::~Own() at memory.h:204:26
kj::AsyncIoContext::~AsyncIoContext() at async-io.h:876:8
kj::AsyncIoContext::~AsyncIoContext() at async-io.h:876:8
snej::shs::SecretRPCContext::~SecretRPCContext() at SecretRPC.cc:56:9
snej::shs::SecretRPCContext::~SecretRPCContext() at SecretRPC.cc:50:45
snej::shs::SecretRPCContext::~SecretRPCContext() at SecretRPC.cc:50:45
kj::Disposer::Dispose_::dispose() at 
memory.h:522:14
void kj::Disposer::dispose() const at 
memory.h:534:3
kj::Own::dispose() at memory.h:278:17
kj::Own::~Own() at memory.h:204:28
kj::Own::~Own() at memory.h:204:26
snej::shs::SecretRPCClient::Impl::~Impl() at SecretRPC.cc:283:29
snej::shs::SecretRPCClient::Impl::~Impl() at SecretRPC.cc:283:29
kj::_::HeapDisposer::disposeImpl() const at 
memory.h:433:60
kj::Disposer::Dispose_::dispose() at 
memory.h:528:14
void kj::Disposer::dispose() const at 
memory.h:534:3
kj::Own::dispose() at memory.h:278:17
kj::Own::~Own() at memory.h:204:28
kj::Own::~Own() at memory.h:204:26
snej::shs::SecretRPCClient::~SecretRPCClient() at SecretRPC.cc:383:59
snej::shs::SecretRPCClient::~SecretRPCClient() at SecretRPC.cc:383:57
kj::_::HeapDisposer::disposeImpl() const at 
memory.h:433:60
kj::Disposer::Dispose_::dispose() at 
memory.h:528:14
void kj::Disposer::dispose() const at memory.h:534:3
kj::Own::dispose() at memory.h:278:17
kj::Own::~Own() at memory.h:204:28
kj::Own::~Own() at memory.h:204:26
myapp::net::Client::ConnectionImpl::~ConnectionImpl() at Client.cc:281:19
myapp::net::Client::ConnectionImpl::~ConnectionImpl() at Client.cc:281:19
myapp::net::Client::ConnectionImpl::~ConnectionImpl() at Client.cc:281:19
std::__1::default_delete::operator() const at 
unique_ptr.h:57:5
std::__1::unique_ptr >::reset() at 
unique_ptr.h:318:7
std::__1::unique_ptr >::~unique_ptr() at 
unique_ptr.h:272:19
std::__1::unique_ptr >::~unique_ptr() at 
unique_ptr.h:272:17
myapp::net::Client::~Client() at Client.cc:314:21
myapp::net::Client::~Client() at Client.cc:314:21
myapp::SyncTask::_run() at SyncTask.cc:166:5
myapp::SyncTask::run() const at SyncTask.cc:82:9
kj::_::RunnableImpl kj::runCatchingExceptionshttps://groups.google.com/d/msgid/capnproto/59C02C00-95D1-4357-8F26-9E3F8A1C35DC%40mooseyard.com.