[ https://issues.apache.org/jira/browse/DRILL-5435?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16008003#comment-16008003 ]
Andrea Bonanno commented on DRILL-5435: --------------------------------------- Here is the output from the bottom of my log Fragment 1:5 [Error Id: 3dc237d3-0c61-4e2d-b078-f57d9fe08869 on ] org.apache.drill.common.exceptions.UserException: SYSTEM ERROR: IllegalStateException: Memory was leaked by query. Memory leaked: (524288) Allocator(op:1:5:3:ParquetRowGroupScan) 1000000/524288/1056768/10000000000 (res/actual/peak/limit) Fragment 1:5 [Error Id: 3dc237d3-0c61-4e2d-b078-f57d9fe08869 on ] at org.apache.drill.common.exceptions.UserException$Builder.build(UserException.java:544) ~[drill-common-1.10.0.jar:1.10.0] at org.apache.drill.exec.work.fragment.FragmentExecutor.sendFinalState(FragmentExecutor.java:293) [drill-java-exec-1.10.0.jar:1.10.0] at org.apache.drill.exec.work.fragment.FragmentExecutor.cleanup(FragmentExecutor.java:160) [drill-java-exec-1.10.0.jar:1.10.0] at org.apache.drill.exec.work.fragment.FragmentExecutor.run(FragmentExecutor.java:262) [drill-java-exec-1.10.0.jar:1.10.0] at org.apache.drill.common.SelfCleaningRunnable.run(SelfCleaningRunnable.java:38) [drill-common-1.10.0.jar:1.10.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_111] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_111] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_111] Caused by: java.lang.IllegalStateException: Memory was leaked by query. Memory leaked: (524288) Allocator(op:1:5:3:ParquetRowGroupScan) 1000000/524288/1056768/10000000000 (res/actual/peak/limit) at org.apache.drill.exec.memory.BaseAllocator.close(BaseAllocator.java:502) ~[drill-memory-base-1.10.0.jar:1.10.0] at org.apache.drill.exec.ops.OperatorContextImpl.close(OperatorContextImpl.java:149) ~[drill-java-exec-1.10.0.jar:1.10.0] at org.apache.drill.exec.ops.FragmentContext.suppressingClose(FragmentContext.java:422) ~[drill-java-exec-1.10.0.jar:1.10.0] at org.apache.drill.exec.ops.FragmentContext.close(FragmentContext.java:411) ~[drill-java-exec-1.10.0.jar:1.10.0] at org.apache.drill.exec.work.fragment.FragmentExecutor.closeOutResources(FragmentExecutor.java:318) [drill-java-exec-1.10.0.jar:1.10.0] at org.apache.drill.exec.work.fragment.FragmentExecutor.cleanup(FragmentExecutor.java:155) [drill-java-exec-1.10.0.jar:1.10.0] ... 5 common frames omitted 2017-05-12 11:37:46,190 [BitServer-3] WARN o.a.d.e.w.b.ControlMessageHandler - Dropping request to cancel fragment. 26ea6177-235c-c1e1-c31d-38a57a3926f8:1:5 does not exist. 2017-05-12 11:37:46,192 [Client-1] ERROR o.a.d.exec.server.rest.QueryWrapper - Query Failed org.apache.drill.common.exceptions.UserRemoteException: SYSTEM ERROR: IllegalStateException: Memory was leaked by query. Memory leaked: (524288) Allocator(op:1:5:3:ParquetRowGroupScan) 1000000/524288/1056768/10000000000 (res/actual/peak/limit) Fragment 1:5 [Error Id: 3dc237d3-0c61-4e2d-b078-f57d9fe08869 on ] at org.apache.drill.exec.rpc.user.QueryResultHandler.resultArrived(QueryResultHandler.java:123) [drill-java-exec-1.10.0.jar:1.10.0] at org.apache.drill.exec.rpc.user.UserClient.handle(UserClient.java:343) [drill-java-exec-1.10.0.jar:1.10.0] at org.apache.drill.exec.rpc.user.UserClient.handle(UserClient.java:88) [drill-java-exec-1.10.0.jar:1.10.0] at org.apache.drill.exec.rpc.RpcBus$InboundHandler.decode(RpcBus.java:274) [drill-rpc-1.10.0.jar:1.10.0] at org.apache.drill.exec.rpc.RpcBus$InboundHandler.decode(RpcBus.java:244) [drill-rpc-1.10.0.jar:1.10.0] at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:89) [netty-codec-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:254) [netty-handler-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103) [netty-codec-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:242) [netty-codec-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:847) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:131) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354) [netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:111) [netty-common-4.0.27.Final.jar:4.0.27.Final] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_111] 2017-05-12 11:37:46,194 [qtp2036240117-1491] ERROR o.a.d.e.server.rest.QueryResources - Query from Web UI Failed org.apache.drill.common.exceptions.UserRemoteException: SYSTEM ERROR: IllegalStateException: Memory was leaked by query. Memory leaked: (524288) Allocator(op:1:5:3:ParquetRowGroupScan) 1000000/524288/1056768/10000000000 (res/actual/peak/limit) Fragment 1:5 [Error Id: 3dc237d3-0c61-4e2d-b078-f57d9fe08869 on ] at org.apache.drill.exec.rpc.user.QueryResultHandler.resultArrived(QueryResultHandler.java:123) ~[drill-java-exec-1.10.0.jar:1.10.0] at org.apache.drill.exec.rpc.user.UserClient.handle(UserClient.java:343) ~[drill-java-exec-1.10.0.jar:1.10.0] at org.apache.drill.exec.rpc.user.UserClient.handle(UserClient.java:88) ~[drill-java-exec-1.10.0.jar:1.10.0] at org.apache.drill.exec.rpc.RpcBus$InboundHandler.decode(RpcBus.java:274) ~[drill-rpc-1.10.0.jar:1.10.0] at org.apache.drill.exec.rpc.RpcBus$InboundHandler.decode(RpcBus.java:244) ~[drill-rpc-1.10.0.jar:1.10.0] at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:89) ~[netty-codec-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:254) ~[netty-handler-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103) ~[netty-codec-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:242) ~[netty-codec-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:847) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:131) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354) ~[netty-transport-4.0.27.Final.jar:4.0.27.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:111) ~[netty-common-4.0.27.Final.jar:4.0.27.Final] at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_111] > Using Limit causes Memory Leaked Error since 1.10 > ------------------------------------------------- > > Key: DRILL-5435 > URL: https://issues.apache.org/jira/browse/DRILL-5435 > Project: Apache Drill > Issue Type: Bug > Components: Storage - Parquet > Affects Versions: 1.10.0 > Reporter: F Méthot > Assignee: Parth Chandra > > Here is the details I can provide: > We migrated our production system from Drill 1.9 to 1.10 just 5 days ago. > (220 nodes cluster) > Our log show there was some 900+ queries ran without problem in first 4 days. > (similar queries, that never use the `limit` clause) > Yesterday we started doing simple adhoc select * ... limit 10 queries (like > we often do, that was our first use of limit with 1.10) > and we got a `Memory was leaked` exception below. > Also, once we get the error, Most of all subsequent user queries fails with > Channel Close Exception. We need to restart Drill to bring it back to normal. > A day later, I used a similar select * limit 10 queries, and the same thing > happen, had to restart Drill. > In the exception, it was refering to a file (1_0_0.parquet) > I moved that file to smaller test cluster (12 nodes) and got the error on the > first attempt. but I am no longer able to reproduce the issue on that file. > Between the 12 and 220 nodes cluster, a different Column name and Row Group > Start was listed in the error. > The parquet file was generated by Drill 1.10. > I tried the same file with a local drill-embedded 1.9 and 1.10 and had no > issue. > Here is the error (manually typed), if you think of anything obvious, let us > know. > AsyncPageReader - User Error Occured: Exception Occurred while reading from > disk (can not read class o.a.parquet.format.PageHeader: java.io.IOException: > input stream is closed.) > File:..../1_0_0.parquet > Column: StringColXYZ > Row Group Start: 115215476 > [Error Id: ....] > at UserException.java:544) > at > o.a.d.exec.store.parquet.columnreaders.AsyncPageReader.handleAndThrowException(AsynvPageReader.java:199) > at > o.a.d.exec.store.parquet.columnreaders.AsyncPageReader.access(AsynvPageReader.java:81) > at > o.a.d.exec.store.parquet.columnreaders.AsyncPageReader.AsyncPageReaderTask.call(AsyncPageReader.java:483) > at > o.a.d.exec.store.parquet.columnreaders.AsyncPageReader.AsyncPageReaderTask.call(AsyncPageReader.java:392) > at > o.a.d.exec.store.parquet.columnreaders.AsyncPageReader.AsyncPageReaderTask.call(AsyncPageReader.java:392) > ... > Caused by: java.io.IOException: can not read class > org.apache.parquet.format.PageHeader: java.io.IOException: Input Stream is > closed. > at o.a.parquet.format.Util.read(Util.java:216) > at o.a.parquet.format.Util.readPageHeader(Util.java:65) > at > o.a.drill.exec.store.parquet.columnreaders.AsyncPageReader(AsyncPageReaderTask:430) > Caused by: parquet.org.apache.thrift.transport.TTransportException: Input > stream is closed > at ...read(TIOStreamTransport.java:129) > at ....TTransport.readAll(TTransport.java:84) > at ....TCompactProtocol.readByte(TCompactProtocol.java:474) > at ....TCompactProtocol.readFieldBegin(TCompactProtocol.java:481) > at ....InterningProtocol.readFieldBegin(InterningProtocol.java:158) > at ....o.a.parquet.format.PageHeader.read(PageHeader.java:828) > at ....o.a.parquet.format.Util.read(Util.java:213) > Fragment 0:0 > [Error id: ...] > o.a.drill.common.exception.UserException: SYSTEM ERROR: > IllegalStateException: Memory was leaked by query. Memory leaked: (524288) > Allocator(op:0:0:4:ParquetRowGroupScan) 1000000/524288/39919616/10000000000 > at o.a.d.common.exceptions.UserException (UserException.java:544) > at > o.a.d.exec.work.fragment.FragmentExecutor.sendFinalState(FragmentExecutor.java:293) > at o.a.d.exec.work.fragment.FragmentExecutor.cleanup( > FragmentExecutor.java:160) > at o.a.d.exec.work.fragment.FragmentExecutor.run(FragmentExecutor.java:262) > ... > Caused by: IllegalStateException: Memory was leaked by query. Memory leaked: > (524288) > at o.a.d.exec.memory.BaseAllocator.close(BaseAllocator.java:502) > at o.a.d.exec.ops.OperatorContextImpl(OperatorContextImpl.java:149) > at o.a.d.exec.ops.FragmentContext.suppressingClose(FragmentContext.java:422) > at o.a.d.exec.ops.FragmentContext.close(FragmentContext.java:411) > at > o.a.d.exec.work.fragment.FragmentExecutor.closeOutResources(FragmentExecutor.java:318) > at > o.a.d.exec.work.fragment.FragmentExecutor.cleanup(FragmentExecutor.java:155) > This fixed the problem: > alter <session|system> set `store.parquet.reader.pagereader.async`=false; -- This message was sent by Atlassian JIRA (v6.3.15#6346)