Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

WARN KQueueEventLoop - events[[1, 88, -1]]=[[1, 88, -1], {}] had no channel! #8849

Closed
amizurov opened this issue Feb 6, 2019 · 11 comments · Fixed by #8881
Closed

WARN KQueueEventLoop - events[[1, 88, -1]]=[[1, 88, -1], {}] had no channel! #8849

amizurov opened this issue Feb 6, 2019 · 11 comments · Fixed by #8881
Assignees
Labels
Milestone

Comments

@amizurov
Copy link
Contributor

@amizurov amizurov commented Feb 6, 2019

Expected behavior

No warning 2019-02-06 23:05:16.068 [KQueueEventLoopGroup-2-2] WARN i.n.channel.kqueue.KQueueEventLoop - events[[1, 88, -1]]=[[1, 88, -1], {}] had no channel!

Actual behavior

Unexpected warning when client application kill -9 or reset peer
2019-02-06 23:05:16.068 [KQueueEventLoopGroup-2-2] WARN i.n.channel.kqueue.KQueueEventLoop - events[[1, 88, -1]]=[[1, 88, -1], {}] had no channel!

Not received reset peer exception in exceptionCaught(ChannelHandlerContext ctx, Throwable cause)
when interrupt client socket

Steps to reproduce

Run snippet code below and kill client

Minimal yet complete reproducer code (or URL to code)

public class ClientKQueue {

public static void main(String[] args) throws Exception {
    Bootstrap clientBootstrap = new Bootstrap()
        .channel(KQueueSocketChannel.class).group(new KQueueEventLoopGroup())
        .handler(new ChannelInboundHandlerAdapter());
    Channel channel = clientBootstrap.connect("localhost", 8080).awaitUninterruptibly().channel();

    channel.closeFuture().awaitUninterruptibly();
}

}

public class ServerKQueue {

public static void main(String[] args) {
    ServerBootstrap serverBootstrap = new ServerBootstrap()
        .channel(KQueueServerSocketChannel.class).group(new KQueueEventLoopGroup())
        .childHandler(new ChannelInitializer() {

            @Override
            protected void initChannel(Channel ch) throws Exception {
                ch.pipeline()
                    .addLast(new ChannelInboundHandlerAdapter() {

                        @Override
                        public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) throws Exception {
                            System.out.println(cause.getMessage());
                        }
                    });
            }
        });

    Channel channel = serverBootstrap.bind(8080).awaitUninterruptibly().channel();
    channel.closeFuture().awaitUninterruptibly();
}

}

Netty version

4.1.33

JVM version (e.g. java -version)

java version "1.8.0_181"
Java(TM) SE Runtime Environment (build 1.8.0_181-b13)
Java HotSpot(TM) 64-Bit Server VM (build 25.181-b13, mixed mode)

OS version (e.g. uname -a)

18.2.0 Darwin Kernel Version 18.2.0: Mon Nov 12 20:24:46 PST 2018; root:xnu-4903.231.4~2/RELEASE_X86_64 x86_64

@amizurov

This comment has been minimized.

Copy link
Contributor Author

@amizurov amizurov commented Feb 6, 2019

Hi, @normanmaurer I think it's related with Fix ClassCastException and native crash when using kqueue transport. (#8665)

@normanmaurer

This comment has been minimized.

Copy link
Member

@normanmaurer normanmaurer commented Feb 7, 2019

will check

@amizurov

This comment has been minimized.

Copy link
Contributor Author

@amizurov amizurov commented Feb 7, 2019

will check

Thanks a lot. If you need additional info, ping me.

@normanmaurer

This comment has been minimized.

Copy link
Member

@normanmaurer normanmaurer commented Feb 7, 2019

@amizurov hmm how does your code reproduce this ? Where do you interrupt the socket ?

@amizurov

This comment has been minimized.

Copy link
Contributor Author

@amizurov amizurov commented Feb 7, 2019

@normanmaurer Sorry if not clear, in this example I simple kill -9 client in 4.1.32 it's work fine, but in 4.1.33 I got a WARN .. had no channel!. I'll tried make reproducer with reset by peer exception, that I caught on production system and I expected but in 4.1.33 this not happened

@kachayev

This comment has been minimized.

Copy link
Contributor

@kachayev kachayev commented Feb 8, 2019

I'm working on introducing KQueue transport support to the Aleph library, and I can confirm that with 4.1.33.Final such warnings happen pretty randomly, hard to tell what is the root cause.

user=> [aleph-netty-client-event-pool-1] WARN io.netty.channel.kqueue.KQueueEventLoop - events[1]=[69, -1] had no channel!
user=> [aleph-netty-client-event-pool-2] WARN io.netty.channel.kqueue.KQueueEventLoop - events[1]=[71, -1] had no channel!
normanmaurer added a commit that referenced this issue Feb 22, 2019
…ue transport

Motivation:

In #8665 we changed how we handle the registration of Channels to KQueue but missed to removed some code which would deregister the Channel before it actual closed the underlying socket. This could lead to have events triggered still while not have a mapping to the Channel anymore.

Modifications:

Remove deregister call during socket closure.

Result:

Fixes #8849.
@normanmaurer

This comment has been minimized.

Copy link
Member

@normanmaurer normanmaurer commented Feb 22, 2019

@amizurov @kachayev can you check #8881 ?

@kachayev

This comment has been minimized.

Copy link
Contributor

@kachayev kachayev commented Feb 22, 2019

@normanmaurer I'll check in a couple of hours.

p.s. One small thing, I think test.log was added by mistake.

@normanmaurer

This comment has been minimized.

Copy link
Member

@normanmaurer normanmaurer commented Feb 22, 2019

@kachayev ups yes... let me remove.

normanmaurer added a commit that referenced this issue Feb 22, 2019
…ue transport

Motivation:

In #8665 we changed how we handle the registration of Channels to KQueue but missed to removed some code which would deregister the Channel before it actual closed the underlying socket. This could lead to have events triggered still while not have a mapping to the Channel anymore.

Modifications:

Remove deregister call during socket closure.

Result:

Fixes #8849.
@kachayev

This comment has been minimized.

Copy link
Contributor

@kachayev kachayev commented Feb 22, 2019

@normanmaurer Nice! Works on my end. I didn't have a strong reproducer but I saw quite a few WARN messages while running my tests. No I don't see any of those. Thanks.

@amizurov

This comment has been minimized.

Copy link
Contributor Author

@amizurov amizurov commented Feb 24, 2019

@normanmaurer Thanks, looks good. No more WARN messages on my side.

normanmaurer added a commit that referenced this issue Feb 25, 2019
…ue transport (#8881)

Motivation:

In #8665 we changed how we handle the registration of Channels to KQueue but missed to removed some code which would deregister the Channel before it actual closed the underlying socket. This could lead to have events triggered still while not have a mapping to the Channel anymore.

Modifications:

Remove deregister call during socket closure.

Result:

Fixes #8849.
@normanmaurer normanmaurer self-assigned this Feb 25, 2019
@normanmaurer normanmaurer added this to the 4.1.34.Final milestone Feb 25, 2019
normanmaurer added a commit that referenced this issue Feb 25, 2019
…ue transport (#8881)

Motivation:

In #8665 we changed how we handle the registration of Channels to KQueue but missed to removed some code which would deregister the Channel before it actual closed the underlying socket. This could lead to have events triggered still while not have a mapping to the Channel anymore.

Modifications:

Remove deregister call during socket closure.

Result:

Fixes #8849.
@normanmaurer normanmaurer added the defect label Feb 25, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
3 participants
You can’t perform that action at this time.