Hi Alexey,
No, I didn’t have the testcase yet. Sometimes I saw errors in production
environments. (Actually, I could rarely meet the EOFException.)
Later, I will try to write a testcase and investigate causes more as your
hint.
Thanks!
Regards,
Bongjae Chang
From: Oleksiy Stashok <oleksiy.stashok_at_oracle.com>
Reply-To: <dev_at_grizzly.java.net>
Date: Wednesday, August 6, 2014 at 2:59 AM
To: <dev_at_grizzly.java.net>
Subject: Re: Strange filter chaining when an EOFException occurred
Hi Bongjae,
my guess is that the same FilterChainContext is used simultaneously by 2
(or more) FilterChains. This may happen when FilterChainContext is recycled,
but still used.
You said it's difficult to reproduce, but is there a testcase, which fails
even if it happens rarely?
Thank you.
WBR,
Alexey.
On 05.08.14 02:29, Bongjae Chang wrote:
>
>
>
> Hi,
>
>
> When I met an EOFException at the TCPNIOTransportFilter, I saw some strange
> filter chainings.
>
> I have two TCPNIOTransports.
>
>
> 1. Custom client: it has only two filters(TransportFilter --> MyCustomFilter)
> 2. HttpServer using AJP protocol: it maybe has two more
> filters(TransportFilter --> httpServerCodecFilter --> IdleTimeoutFilter -->
> ...)
>
> First, HttpServer received AJP packets then the specific HttpHandler called
> the custom API with the custom client.
> If the http server met EOFException, the following exception occurred. I
> replaced real IP and domain into ${http_server_IP},${custom_server_domain} and
> ${custom_server_IP}.
>
> ====
> 8월 01, 2014 9:38:30 오전 org.glassfish.grizzly.http.server.HttpHandler doHandle
> 경고: GRIZZLY0200: Service exception
> java.io.EOFException
> at
> org.glassfish.grizzly.nio.transport.TCPNIOTransport.read(TCPNIOTransport.java:
> 632)
> at
> org.glassfish.grizzly.nio.transport.TCPNIOTransportFilter.handleRead(TCPNIOTra
> nsportFilter.java:75)
> at
> org.glassfish.grizzly.filterchain.TransportFilter.handleRead(TransportFilter.j
> ava:173)
> at
> org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.
> java:119)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilt
> erChain.java:284)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultF
> ilterChain.java:201)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChai
> n.java:133)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChai
> n.java:112)
> at
> org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
> at
> org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTranspor
> t.java:561)
> at
> org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStra
> tegy.java:112)
> at
> org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStr
> ategy.java:117)
> at
> org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThrea
> dIOStrategy.java:56)
> at
> org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.r
> un(WorkerThreadIOStrategy.java:137)
> at
> com.kakao.common.util.StatisticKakaoThreadPoolExecutor$StatisticRunnable.run(S
> tatisticKakaoThreadPoolExecutor.java:278)
> at
> com.kakao.common.util.KakaoThreadPoolExecutor$Worker.runTask(KakaoThreadPoolEx
> ecutor.java:950)
> at
> com.kakao.common.util.KakaoThreadPoolExecutor$Worker.run(KakaoThreadPoolExecut
> or.java:987)
> at java.lang.Thread.run(Thread.java:744)
>
> 8월 01, 2014 9:38:30 오전 org.glassfish.grizzly.http.server.Request
> onAfterService
> 경고: GRIZZLY0204: Unexpected error during afterService notification
> java.lang.NullPointerException
> at
> org.glassfish.grizzly.filterchain.FilterChainContext.notifyDownstream(FilterCh
> ainContext.java:895)
> at
> org.glassfish.grizzly.filterchain.FilterChainContext.notifyDownstream(FilterCh
> ainContext.java:890)
> at
> org.glassfish.grizzly.http.server.HttpServerFilter$FlushResponseHandler.onAfte
> rService(HttpServerFilter.java:470)
> at
> org.glassfish.grizzly.http.server.Request.onAfterService(Request.java:582)
> at
> org.glassfish.grizzly.http.server.HttpServerFilter.afterService(HttpServerFilt
> er.java:385)
> at
> org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter
> .java:260)
> at
> org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.
> java:119)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilt
> erChain.java:284)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultF
> ilterChain.java:201)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChai
> n.java:133)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChai
> n.java:112)
> at
> org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
> at
> org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTranspor
> t.java:561)
> at
> org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStra
> tegy.java:112)
> at
> org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStr
> ategy.java:117)
> at
> org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThrea
> dIOStrategy.java:56)
> at
> org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.r
> un(WorkerThreadIOStrategy.java:137)
> at
> com.kakao.common.util.StatisticKakaoThreadPoolExecutor$StatisticRunnable.run(S
> tatisticKakaoThreadPoolExecutor.java:278)
> at
> com.kakao.common.util.KakaoThreadPoolExecutor$Worker.runTask(KakaoThreadPoolEx
> ecutor.java:950)
> at
> com.kakao.common.util.KakaoThreadPoolExecutor$Worker.run(KakaoThreadPoolExecut
> or.java:987)
> at java.lang.Thread.run(Thread.java:744)
>
> 8월 01, 2014 9:38:30 오전 org.glassfish.grizzly.filterchain.DefaultFilterChain
> execute
> 경고: GRIZZLY0013: Exception during FilterChain execution
> java.lang.IndexOutOfBoundsException: Index: 5, Size: 2
> at java.util.ArrayList.rangeCheck(ArrayList.java:635)
> at java.util.ArrayList.get(ArrayList.java:411)
> at
> org.glassfish.grizzly.filterchain.ListFacadeFilterChain.get(ListFacadeFilterCh
> ain.java:145)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultF
> ilterChain.java:193)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChai
> n.java:133)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChai
> n.java:112)
> at
> org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.write(DefaultFilterChain.
> java:413)
> at
> org.glassfish.grizzly.nio.NIOConnection.write(NIOConnection.java:407)
> at
> org.glassfish.grizzly.nio.NIOConnection.write(NIOConnection.java:371)
> at
> com.kakao.common.client.AbstractClient.sendInternal(AbstractClient.java:582)
> at
> com.kakao.capri.alfs.client.CapriAlfsClient.increaseAndCheck(CapriAlfsClient.j
> ava:46)
> at
> com.kakao.capri.alfs.client.spring.GrizzlyAlfsClientBean.increaseAndCheck(Griz
> zlyAlfsClientBean.java:300)
> at
> com.kakao.capri.api.server.alfs.AlfsClientDelegator.increaseAndCheck(AlfsClien
> tDelegator.java:178)
> at
> com.kakao.capri.api.server.alfs.AlfsClientDelegator.increaseAndCheck(AlfsClien
> tDelegator.java:156)
> at
> com.kakao.capri.api.server.handler.APIHandler.checkAlfsFilter(APIHandler.java:
> 130)
> at
>
com.kakao.capri.api.server.handler.APIHandler.beforeService(APIHandler.java:81>
)
> at
> com.kakao.server.web.handler.GrizzlyHandler.service(GrizzlyHandler.java:127)
> at
> org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:201)
> at
> org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:175)
> at
> org.glassfish.grizzly.http.server.HttpHandlerChain.doHandle(HttpHandlerChain.j
> ava:223)
> at
> org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter
> .java:235)
> at
> org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.
> java:119)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilt
> erChain.java:284)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultF
> ilterChain.java:201)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChai
> n.java:133)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChai
> n.java:112)
> at
> org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
> at
> org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTranspor
> t.java:561)
> at
> org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStra
> tegy.java:112)
> at
> org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStr
> ategy.java:117)
> at
> org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThrea
> dIOStrategy.java:56)
> at
> org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.r
> un(WorkerThreadIOStrategy.java:137)
> at
> com.kakao.common.util.StatisticKakaoThreadPoolExecutor$StatisticRunnable.run(S
> tatisticKakaoThreadPoolExecutor.java:278)
> at
> com.kakao.common.util.KakaoThreadPoolExecutor$Worker.runTask(KakaoThreadPoolEx
> ecutor.java:950)
> at
> com.kakao.common.util.KakaoThreadPoolExecutor$Worker.run(KakaoThreadPoolExecut
> or.java:987)
> at java.lang.Thread.run(Thread.java:744)
>
> 8월 01, 2014 9:38:30 오전 org.glassfish.grizzly.ProcessorExecutor execute
> 경고: GRIZZLY0029: Error during Processor execution.
> Connection=TCPNIOConnection{localSocketAddress={/${http_server_IP}:33824},
> peerSocketAddress={${custom_server_domain}/${custom_server_IP}:10000}}
> ioEvent=READ
> processor=org.glassfish.grizzly.filterchain.DefaultFilterChain_at_55ef2704
> java.lang.IndexOutOfBoundsException: Index: 6, Size: 2
> at java.util.ArrayList.rangeCheck(ArrayList.java:635)
> at java.util.ArrayList.get(ArrayList.java:411)
> at
> org.glassfish.grizzly.filterchain.ListFacadeFilterChain.get(ListFacadeFilterCh
> ain.java:145)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.throwChain(DefaultFilterC
> hain.java:478)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChai
> n.java:159)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChai
> n.java:112)
> at
> org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.write(DefaultFilterChain.
> java:413)
> at
> org.glassfish.grizzly.nio.NIOConnection.write(NIOConnection.java:407)
> at
> org.glassfish.grizzly.nio.NIOConnection.write(NIOConnection.java:371)
> at
> com.kakao.common.client.AbstractClient.sendInternal(AbstractClient.java:582)
> at
> com.kakao.capri.alfs.client.CapriAlfsClient.increaseAndCheck(CapriAlfsClient.j
> ava:46)
> at
> com.kakao.capri.alfs.client.spring.GrizzlyAlfsClientBean.increaseAndCheck(Griz
> zlyAlfsClientBean.java:300)
> at
> com.kakao.capri.api.server.alfs.AlfsClientDelegator.increaseAndCheck(AlfsClien
> tDelegator.java:178)
> at
> com.kakao.capri.api.server.alfs.AlfsClientDelegator.increaseAndCheck(AlfsClien
> tDelegator.java:156)
> at
> com.kakao.capri.api.server.handler.APIHandler.checkAlfsFilter(APIHandler.java:
> 130)
> at
>
com.kakao.capri.api.server.handler.APIHandler.beforeService(APIHandler.java:81>
)
> at
> com.kakao.server.web.handler.GrizzlyHandler.service(GrizzlyHandler.java:127)
> at
> org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:201)
> at
> org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:175)
> at
> org.glassfish.grizzly.http.server.HttpHandlerChain.doHandle(HttpHandlerChain.j
> ava:223)
> at
> org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter
> .java:235)
> at
> org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.
> java:119)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilt
> erChain.java:284)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultF
> ilterChain.java:201)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChai
> n.java:133)
> at
> org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChai
> n.java:112)
> at
> org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
> at
> org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTranspor
> t.java:561)
> at
> org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStra
> tegy.java:112)
> at
> org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStr
> ategy.java:117)
> at
> org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThrea
> dIOStrategy.java:56)
> at
> org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.r
> un(WorkerThreadIOStrategy.java:137)
> at
> com.kakao.common.util.StatisticKakaoThreadPoolExecutor$StatisticRunnable.run(S
> tatisticKakaoThreadPoolExecutor.java:278)
> at
> com.kakao.common.util.KakaoThreadPoolExecutor$Worker.runTask(KakaoThreadPoolEx
> ecutor.java:950)
> at
> com.kakao.common.util.KakaoThreadPoolExecutor$Worker.run(KakaoThreadPoolExecut
> or.java:987)
> at java.lang.Thread.run(Thread.java:744)
> ===
>
> I don't know whether the thread of stack traces is same or not. But I know
> the custom client has only two filter chains but it seems that it tries to
> refer to http filters.
> I think maybe current FilterChainContext or internalContext was wrong. In the
> last exception, peerSocketAddress was correct but DefaultFilterChain tried to
> get index 6 and you can see a NPE during getting getFilterChain() in
> FilterChainContext.
>
> Unfortunately, it is not easy to reproduce it. And I used grizzly version
> v2.3.13.
>
> Could I get some hints about this issue?
>
>
>
>
>
>
> Thanks!
>
>
>
>
> Regards,
>
> Bongjae Chang
>
>
>
>
>