playframework / play1

Play framework
https://www.playframework.com/documentation/1.4.x/home
Other
1.58k stars 684 forks source link

(WIP) Migration to Netty 4 #1284

Open tomparle opened 5 years ago

tomparle commented 5 years ago

Hi,

I wanted to migrate from old Netty 3.x to 4.1.x, which might offer some performance and memory enhancements, see https://netty.io/wiki/new-and-noteworthy-in-4.0.html and https://blog.twitter.com/engineering/en_us/a/2013/netty-4-at-twitter-reduced-gc-overhead.html.

It appears that the migration is tougher than I thought, and I cannot make it work : Play is stuck when starting the application. Nevertheless, I think I still have done a big part of the work, replacing deprecated calls and updated new API calls. I removed all compilation errors and there is no error on startup. I guess I lack the necessary understanding to solve the remaining issues, so I just want to share the work in progress and welcome any help to finish the job !

The changes so far have been commited in this branch : https://github.com/tomparle/play1/tree/libupgrade . Tell me if it should be transformed in pull request or anything else.

asolntsev commented 5 years ago

@tomparle great, thank you! I also wanted to upgrade to Netty 4, but failed even with compilation errors. So, you have achieved greater success :)

I will try to run your version. No pull tequest is needed at the moment.

tomparle commented 5 years ago

Thanks @asolntsev for the kind message ! It motivates me to go further :-) Just some notes about some choices I made:

Let's discuss this more when you have some time to review the changes, and thanks again for your contribution !

xabolcs commented 4 years ago

Looks like the New and noteworthy in 4.0 should be carefully read and understand, and play.server.PlayHandler (or the whole play.server package?) has to be refactored / updated for Netty 4.

xabolcs commented 4 years ago

Hi @tomparle, I did the upgrade based on your work, and was able to start normally.

For test I used the example from #1304.

It starts up nicely:

...
08:39:48,816 DEBUG ~ [main] -Dio.netty.allocator.type: pooled
08:39:48,816 DEBUG ~ [main] -Dio.netty.threadLocalDirectBufferSize: 0
08:39:48,816 DEBUG ~ [main] -Dio.netty.maxThreadLocalCharBufferSize: 16384
08:39:48,823 WARN  ~ [main] Unknown channel option 'TCP_NODELAY' for channel '[id: 0xccd2fe56]'
08:39:48,829 INFO  ~ [main] Listening for HTTP on port 9000 ...
08:39:56,655 DEBUG ~ [nioEventLoopGroup-3-1] -Dio.netty.buffer.checkAccessible: true
08:39:56,655 DEBUG ~ [nioEventLoopGroup-3-1] -Dio.netty.buffer.checkBounds: true
08:39:56,655 DEBUG ~ [nioEventLoopGroup-3-1] Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@190551e0
08:39:56,674 DEBUG ~ [nioEventLoopGroup-3-1] -Dio.netty.recycler.maxCapacityPerThread: 4096
08:39:56,674 DEBUG ~ [nioEventLoopGroup-3-1] -Dio.netty.recycler.maxSharedCapacityFactor: 2
08:39:56,674 DEBUG ~ [nioEventLoopGroup-3-1] -Dio.netty.recycler.linkCapacity: 16
08:39:56,674 DEBUG ~ [nioEventLoopGroup-3-1] -Dio.netty.recycler.ratio: 8

And it starts serving the request too:

08:39:56,709 INFO  ~ [play-thread-1] before await
08:39:56,709 INFO  ~ [pool-1-thread-1] before sleep
08:39:56,709 DEBUG ~ [play-thread-1] suspend()
08:39:56,710 DEBUG ~ [play-thread-1] push object java.util.concurrent.FutureTask@1174841259/unknown [java.util.concurrent.FutureTask@4606a7ab] i[0],l[0],d[0],f[0],o[0],r[0]
08:39:56,710 DEBUG ~ [play-thread-1] push int 2 i[0],l[0],d[0],f[0],o[1],r[0]
08:39:56,711 WARN  ~ [play-thread-1] Start WaitForTasksCompletion

But after continuation it dies with IndexOutOfBoundsException while creating the response :upside_down_face: :

08:40:16,709 INFO  ~ [pool-1-thread-1] after sleep
08:40:16,729 DEBUG ~ [play-thread-1] pop int 2 i[0],l[0],d[0],f[0],o[1],r[0]
08:40:16,730 DEBUG ~ [play-thread-1] pop object java.util.concurrent.FutureTask@1174841259/unknown [java.util.concurrent.FutureTask@4606a7ab] 
08:40:16,734 INFO  ~ [play-thread-1] after await
08:40:16,907 ERROR ~ [play-thread-1] 

@7f516akoo
Internal Server Error (500) for request GET /

Oops: IndexOutOfBoundsException
Unexpected error : Unexpected Error, caused by exception IndexOutOfBoundsException: index: 0, length: 514 (expected: range(0, 256))

play.exceptions.UnexpectedException: Unexpected Error
    at play.Invoker$Invocation.onException(Invoker.java:270)
    at play.Invoker$Invocation.run(Invoker.java:334)
    at play.server.AbstractPlayHandler$NettyInvocation.run(AbstractPlayHandler.java:270)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IndexOutOfBoundsException: index: 0, length: 514 (expected: range(0, 256))
    at io.netty.buffer.AbstractByteBuf.checkRangeBounds(AbstractByteBuf.java:1425)
    at io.netty.buffer.AbstractByteBuf.checkIndex0(AbstractByteBuf.java:1432)
    at io.netty.buffer.AbstractByteBuf.checkIndex(AbstractByteBuf.java:1419)
    at io.netty.buffer.AbstractByteBuf.checkSrcIndex(AbstractByteBuf.java:1437)
    at io.netty.buffer.UnpooledHeapByteBuf.setBytes(UnpooledHeapByteBuf.java:260)
    at io.netty.buffer.AbstractByteBuf.setBytes(AbstractByteBuf.java:631)
    at play.server.AbstractPlayHandler.writeResponse(AbstractPlayHandler.java:404)
    at play.server.AbstractPlayHandler.copyResponse(AbstractPlayHandler.java:515)
    at play.server.AbstractPlayHandler$NettyInvocation.onSuccess(AbstractPlayHandler.java:302)
    at play.Invoker$Invocation.run(Invoker.java:328)
    ... 8 more
08:40:16,908 ERROR ~ [play-thread-1] Error during the 500 response generation
java.lang.IndexOutOfBoundsException: index: 0, length: 417 (expected: range(0, 256))
    at io.netty.buffer.AbstractByteBuf.checkRangeBounds(AbstractByteBuf.java:1425)
    at io.netty.buffer.AbstractByteBuf.checkIndex0(AbstractByteBuf.java:1432)
    at io.netty.buffer.AbstractByteBuf.checkIndex(AbstractByteBuf.java:1419)
    at io.netty.buffer.AbstractByteBuf.checkSrcIndex(AbstractByteBuf.java:1437)
    at io.netty.buffer.UnpooledHeapByteBuf.setBytes(UnpooledHeapByteBuf.java:260)
    at io.netty.buffer.AbstractByteBuf.setBytes(AbstractByteBuf.java:631)
    at play.server.AbstractPlayHandler.serve500(AbstractPlayHandler.java:803)
    at play.server.AbstractPlayHandler$NettyInvocation.run(AbstractPlayHandler.java:272)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
^C
Terminating Java process

The AbstractPlayHandler above is just the plain old PlayHandler, just renamed.

xabolcs commented 4 years ago

I wanted to introduce the Netty4 library in 2+1 steps:

  1. add to framework, independently from Netty3
  2. switch to Netty4
  3. drop Netty3

It seemed to be doable, as Netty 4 is now io.netty while Netty 3 is org.jboss.netty. But sadly there are two Netty 3 dependency outside of play.server.*:

They depend on org.jboss.netty.channel.ChannelHandlerContext especially Channel.setReadable(boolean). Unsurprisingly it's related to inbound flow control which has a topic in the "New and noteworthy" document: Sensible and less error-prone inbound traffic suspension

At first sight I thought about new interface, based on ChannelHandlerContext/BlockingEventStream and implementations for Netty 3 and Netty 4.

Sure, BlockingEventStream should be rewritten.

Any thoughts?

tomparle commented 4 years ago

First, thank you very much @xabolcs for your contribution ! This migration seems to be no easy-task and I appreciate that other people join in.

About the migration step : what would be the point to have both Netty 3 and 4 at the same time ? My opinion is that it would just bring up more problems. I would rather suggest to migrate to Netty 4 directly.

Except for the test #1304, did you try an application of yours to see if you had the same IndexOutOfBoundsException error ? I know my progress was incomplete, especially in the PlayHandler class. Did you make any other changes that I could test ?

xabolcs commented 4 years ago

About the migration step: as you already know this is not just an average version bump, like the PostgreSQL or Hibernate. It's a major version bump. It's more helpful to me to keep a working server around while integrating Netty 4 as a http backend.

I didn't try other apps, will test later when I have progress.

My quick & dirty work in progress solution is templating and registering the handlers, like:

public class FullHttpRequestPlayHandler extends AbstractPlayHandler<FullHttpRequest> {

    @Override
    protected void messageReceived(ChannelHandlerContext ctx, FullHttpRequest msg) throws Exception {
        messageReceivedDefault(ctx, msg);
    }
}

... and:

public abstract class AbstractPlayHandler<I> extends SimpleChannelInboundHandler<I> {
...
    // TODO: Please keep in mind that this method will be renamed to messageReceived(ChannelHandlerContext, I) in 5.0.
    @Override
    protected final void channelRead0(ChannelHandlerContext ctx, I msg) throws Exception {
        messageReceived(ctx, msg);
    }

    // TODO: Netty 5.0!
    abstract protected void messageReceived(ChannelHandlerContext ctx, I msg) throws Exception;

    protected final void messageReceivedDefault(final ChannelHandlerContext ctx, I msg) throws Exception {
        if (Logger.isTraceEnabled()) {
            // this is the plain old messageReceived, just renamed
            Logger.trace("messageReceived: begin");
        }

        // Http request
        if (msg instanceof FullHttpRequest) {

            final FullHttpRequest nettyRequest = (FullHttpRequest) msg;

            // Websocket upgrade
...
xabolcs commented 4 years ago

I didn't try other apps, will test later when I have progress.

I tested, and got the same Exception:

23:13:43,769 ERROR ~ 

@7f5co5bpl
Internal Server Error (500) for request GET /

Oops: IndexOutOfBoundsException
Unexpected error : Unexpected Error, caused by exception IndexOutOfBoundsException: index: 0, length: 3785 (expected: range(0, 256))

play.exceptions.UnexpectedException: Unexpected Error
    at play.Invoker$Invocation.onException(Invoker.java:270)
    at play.Invoker$Invocation.run(Invoker.java:334)
    at play.netty4.server.AbstractPlayHandler$NettyInvocation.run(AbstractPlayHandler.java:271)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IndexOutOfBoundsException: index: 0, length: 3785 (expected: range(0, 256))
    at io.netty.buffer.AbstractByteBuf.checkRangeBounds(AbstractByteBuf.java:1425)
    at io.netty.buffer.AbstractByteBuf.checkIndex0(AbstractByteBuf.java:1432)
    at io.netty.buffer.AbstractByteBuf.checkIndex(AbstractByteBuf.java:1419)
    at io.netty.buffer.AbstractByteBuf.checkSrcIndex(AbstractByteBuf.java:1437)
    at io.netty.buffer.UnpooledHeapByteBuf.setBytes(UnpooledHeapByteBuf.java:260)
    at io.netty.buffer.AbstractByteBuf.setBytes(AbstractByteBuf.java:631)
    at play.netty4.server.AbstractPlayHandler.writeResponse(AbstractPlayHandler.java:405)
    at play.netty4.server.AbstractPlayHandler.copyResponse(AbstractPlayHandler.java:516)
    at play.netty4.server.AbstractPlayHandler$NettyInvocation.onSuccess(AbstractPlayHandler.java:303)
    at play.Invoker$Invocation.run(Invoker.java:328)
    ... 8 more
23:13:43,770 ERROR ~ Error during the 500 response generation
java.lang.IndexOutOfBoundsException: index: 0, length: 2465 (expected: range(0, 256))
    at io.netty.buffer.AbstractByteBuf.checkRangeBounds(AbstractByteBuf.java:1425)
    at io.netty.buffer.AbstractByteBuf.checkIndex0(AbstractByteBuf.java:1432)
    at io.netty.buffer.AbstractByteBuf.checkIndex(AbstractByteBuf.java:1419)
    at io.netty.buffer.AbstractByteBuf.checkSrcIndex(AbstractByteBuf.java:1437)
    at io.netty.buffer.UnpooledHeapByteBuf.setBytes(UnpooledHeapByteBuf.java:260)
    at io.netty.buffer.AbstractByteBuf.setBytes(AbstractByteBuf.java:631)
    at play.netty4.server.AbstractPlayHandler.serve500(AbstractPlayHandler.java:804)
    at play.netty4.server.AbstractPlayHandler$NettyInvocation.run(AbstractPlayHandler.java:273)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
^C
Terminating Java process
xabolcs commented 4 years ago

It appears that the migration is tougher than I thought, and I cannot make it work : Play is stuck when starting the application.

Looks like I reached your 2018 state! :grinning: The response sent (?) but not bits reach the browser.

23:53:21,549 INFO  ~ [play-thread-1] after await
23:53:21,559 TRACE ~ [play-thread-1] 2ms to render template {play}/framework/templates/tags/welcome_en.html
23:53:21,561 TRACE ~ [play-thread-1] 9ms to render template {play}/framework/templates/tags/welcome.html
23:53:21,562 TRACE ~ [play-thread-1] 12ms to render template /app/views/Application/index.html
23:53:21,567 TRACE ~ [play-thread-1] 5ms to render template /app/views/main.html
23:53:21,568 TRACE ~ [play-thread-1] copyResponse: begin
23:53:21,569 TRACE ~ [play-thread-1] writeResponse: begin
23:53:21,569 TRACE ~ [play-thread-1] writeResponse: content length [5743]
23:53:21,569 TRACE ~ [play-thread-1] writeResponse: end
23:53:21,569 TRACE ~ [play-thread-1] copyResponse: end
23:53:21,569 TRACE ~ [play-thread-1] execute: end
23:53:21,570 TRACE ~ [play-thread-1] run: end

I think the problem is that in the new code there are too few flush. I don't know what's missing here.

xabolcs commented 4 years ago

I added channelReadComplete(ctx) to my AbstractPlayHandler and it doesn't fire. :thinking:

    @Override
    public void channelReadComplete(ChannelHandlerContext ctx) throws Exception {
        if (Logger.isTraceEnabled()) {
            Logger.trace("channelReadComplete: begin");
        }
        ctx.flush();
        super.channelReadComplete(ctx);
        if (Logger.isTraceEnabled()) {
            Logger.trace("channelReadComplete: end");
        }

    }
aleksandy commented 2 years ago

@xabolcs, hi. Did you finish migration? Could you share your work? I didn't find its in your fork.

xabolcs commented 2 years ago

Hi @aleksandy !

Sadly it was just abandoned, as it's equivalent to @tomparle's work. :confused: I tried my luck with the replay fork, but it had the same problem:

I have tried your PR and found one problem: serving static resources

Namely, I am trying to open the following URL in a browser: http://localhost:9126/public/images/logo-bspb.svg

and it stays indefinitely in "loading" state. :(

One must rethink Play!'s current integration with Netty 3! It's not portable to Netty 4 in it's current form. I had a few toughts there (codeborne/replay#25), but never tried them.

xabolcs commented 2 years ago

And first of all: one should write a test for "serving static resources"!

xabolcs commented 1 year ago

Hi @tomparle and @aleksandy !

My Netty 4 contribution to the RePlay! fork was accepted. After merging @asolntsev did an awesome heavy lifting to it and now RePlay! works nicely with Netty 3, Netty 4 and with the new plain Java implementation (codeborne/replay#152)!

Feel free to check RePlay!'s code to get some hint!


EDIT: Netty 4 still have problems with static resources: codeborne/replay#157. :disappointed: