search

Netflix / karyon

The nucleus or the base container for Applications and Services built using the NetflixOSS ecosystem
Apache License 2.0
497 stars 153 forks source link

Running out of threads #122

Closed vignessh closed 9 years ago

vignessh commented 10 years ago

I was trying to run some kind of micro benchmark against Karyon to understand how it performs - for that purpose I checked out the Karyon source code and ran ../gradlew runJerseyHelloNOSS from the karyon-examples folder.

And then proceeded to run wrk -d 1s http://localhost:8888/hello/ in a separate terminal. This ran fine without any failures. After which, I commented out a couple of lines from JerseyHelloWorldApp to make it look like below:

@Override
protected void configureServer() {
    // bind(AuthenticationService.class).to(AuthenticationServiceImpl.class);
    // interceptorSupport().forUri("/*").intercept(LoggingInterceptor.class);
    // interceptorSupport().forUri("/hello").interceptIn(AuthInterceptor.class);
    server().port(8888).threadPoolSize(100);
}

Basically commented out the interceptor and authentication bindings. I ran wrk -d 1s http://localhost:8888/hello/ against this change, and got the stack trace as below:

2014-10-23 11:21:08:391 +0530 [rx-request-processor-5-4] WARN io.netty.channel.DefaultChannelPipeline - An exception was thrown by a user handler's exceptionCaught() method while handling the following exception:
java.lang.OutOfMemoryError: unable to create new native thread
    at java.lang.Thread.start0(Native Method)
    at java.lang.Thread.start(Thread.java:714)
    at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:949)
    at java.util.concurrent.ThreadPoolExecutor.ensurePrestart(ThreadPoolExecutor.java:1590)
    at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:333)
    at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:530)
    at java.util.concurrent.ScheduledThreadPoolExecutor.submit(ScheduledThreadPoolExecutor.java:629)
    at rx.internal.schedulers.NewThreadWorker.scheduleActual(NewThreadWorker.java:61)
    at rx.schedulers.CachedThreadScheduler$EventLoopWorker.schedule(CachedThreadScheduler.java:149)
    at rx.schedulers.CachedThreadScheduler$EventLoopWorker.schedule(CachedThreadScheduler.java:139)
    at rx.internal.operators.OperatorSubscribeOn$1.onNext(OperatorSubscribeOn.java:56)
    at rx.internal.operators.OperatorSubscribeOn$1.onNext(OperatorSubscribeOn.java:42)
    at rx.Observable$3.call(Observable.java:1551)
    at rx.Observable$3.call(Observable.java:1546)
    at rx.Observable$2.call(Observable.java:159)
    at rx.Observable$2.call(Observable.java:155)
    at rx.Observable$2.call(Observable.java:159)
    at rx.Observable$2.call(Observable.java:155)
    at rx.Observable.subscribe(Observable.java:6900)
    at io.reactivex.netty.protocol.http.server.HttpConnectionHandler$1$1.onNext(HttpConnectionHandler.java:114)
    at io.reactivex.netty.protocol.http.server.HttpConnectionHandler$1$1.onNext(HttpConnectionHandler.java:62)
    at rx.subjects.SubjectSubscriptionManager$SubjectObserver.onNext(SubjectSubscriptionManager.java:224)
    at rx.subjects.PublishSubject.onNext(PublishSubject.java:101)
    at io.reactivex.netty.pipeline.ObservableAdapter.channelRead(ObservableAdapter.java:40)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:333)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:319)
    at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:333)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:319)
    at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
    at io.reactivex.netty.protocol.http.server.ServerRequestResponseConverter.channelRead(ServerRequestResponseConverter.java:85)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:333)
    at io.netty.channel.AbstractChannelHandlerContext.access$700(AbstractChannelHandlerContext.java:32)
    at io.netty.channel.AbstractChannelHandlerContext$8.run(AbstractChannelHandlerContext.java:324)
    at io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:36)
    at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
    at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137)
    at java.lang.Thread.run(Thread.java:745)
2014-10-23 11:21:08:391 +0530 [rx-request-processor-5-3] WARN io.netty.channel.DefaultChannelPipeline - An exception was thrown by a user handler's exceptionCaught() method while handling the following exception:
java.lang.OutOfMemoryError: unable to create new native thread
    at java.lang.Thread.start0(Native Method)
    at java.lang.Thread.start(Thread.java:714)
    at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:949)
    at java.util.concurrent.ThreadPoolExecutor.ensurePrestart(ThreadPoolExecutor.java:1590)
    at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:333)
    at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:530)
    at java.util.concurrent.ScheduledThreadPoolExecutor.submit(ScheduledThreadPoolExecutor.java:629)
    at rx.internal.schedulers.NewThreadWorker.scheduleActual(NewThreadWorker.java:61)
    at rx.schedulers.CachedThreadScheduler$EventLoopWorker.schedule(CachedThreadScheduler.java:149)
    at rx.schedulers.CachedThreadScheduler$EventLoopWorker.schedule(CachedThreadScheduler.java:139)
    at rx.internal.operators.OperatorSubscribeOn$1.onNext(OperatorSubscribeOn.java:56)
    at rx.internal.operators.OperatorSubscribeOn$1.onNext(OperatorSubscribeOn.java:42)
    at rx.Observable$3.call(Observable.java:1551)
    at rx.Observable$3.call(Observable.java:1546)
    at rx.Observable$2.call(Observable.java:159)
    at rx.Observable$2.call(Observable.java:155)
    at rx.Observable$2.call(Observable.java:159)
    at rx.Observable$2.call(Observable.java:155)
    at rx.Observable.subscribe(Observable.java:6900)
    at io.reactivex.netty.protocol.http.server.HttpConnectionHandler$1$1.onNext(HttpConnectionHandler.java:114)
    at io.reactivex.netty.protocol.http.server.HttpConnectionHandler$1$1.onNext(HttpConnectionHandler.java:62)
    at rx.subjects.SubjectSubscriptionManager$SubjectObserver.onNext(SubjectSubscriptionManager.java:224)
    at rx.subjects.PublishSubject.onNext(PublishSubject.java:101)
    at io.reactivex.netty.pipeline.ObservableAdapter.channelRead(ObservableAdapter.java:40)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:333)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:319)
    at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:333)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:319)
    at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
    at io.reactivex.netty.protocol.http.server.ServerRequestResponseConverter.channelRead(ServerRequestResponseConverter.java:85)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:333)
    at io.netty.channel.AbstractChannelHandlerContext.access$700(AbstractChannelHandlerContext.java:32)
    at io.netty.channel.AbstractChannelHandlerContext$8.run(AbstractChannelHandlerContext.java:324)
    at io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:36)
    at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
    at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137)
    at java.lang.Thread.run(Thread.java:745)

If I uncomment the above said lines, I'm able to run wrk against the service with no failures. How does the addition of interceptor make the service more stable?

maksimlikharev commented 9 years ago

I see this too, basically not quite obvious where the bug is rx-netty or jersey bridge, but in essence scheduler threads created here:

        ThreadWorker get() {
            while (!expiringWorkerQueue.isEmpty()) {
                ThreadWorker threadWorker = expiringWorkerQueue.poll();
                if (threadWorker != null) {
                    return threadWorker;
                }
            }

            // No cached worker found, so create a new one.
            return new ThreadWorker(WORKER_THREAD_FACTORY);
        }

not release in here:

        void release(ThreadWorker threadWorker) {
            // Refresh expire time before putting worker back in pool
            threadWorker.setExpirationTime(now() + keepAliveTime);

            expiringWorkerQueue.offer(threadWorker);
        }

due to missing unsubscribe.

adding any interceptors will workaround the problem, this is a really nasty bug, as it leaks 1 thread per request.

NiteshKant commented 9 years ago

This was fixed by #200