Uploaded image for project: 'Apache Drill'
  1. Apache Drill
  2. DRILL-5398

Memory Allocator randomly throws an IllegalStateException when reading nested json data

    XMLWordPrintableJSON

    Details

      Description

      git.commit.id.abbrev=38ef562

      The below query did not fail when I ran it in isolation. However when I ran the test suite at [1], which also contains the below query, by using 50 threads submitting queries concurrently, I hit the below error.

      select kvgen(bigintegercol), kvgen(float8col) from `json_kvgenflatten/kvgen1.json`
      Failed with exception
      java.sql.SQLException: SYSTEM ERROR: IllegalStateException: Allocator[op:0:0:2:Project] closed with outstanding buffers allocated (6).
      Allocator(op:0:0:2:Project) 1000000/110592/434176/10000000000 (res/actual/peak/limit)
        child allocators: 0
        ledgers: 6
          ledger[2747] allocator: op:0:0:2:Project), isOwning: true, size: 32768, references: 1, life: 13372865831733586..0, allocatorManager: [694, life: 13372864956215117..0] holds 1 buffers. 
              DrillBuf[3165], udle: [694 0..32768]
          ledger[2756] allocator: op:0:0:2:Project), isOwning: true, size: 4096, references: 1, life: 13372865832378236..0, allocatorManager: [702, life: 13372864958396200..0] holds 1 buffers. 
              DrillBuf[3176], udle: [703 0..4096]
          ledger[2775] allocator: op:0:0:2:Project), isOwning: true, size: 32768, references: 1, life: 13372865833922897..0, allocatorManager: [706, life: 13372864959861722..0] holds 1 buffers. 
              DrillBuf[3196], udle: [707 0..32768]
          ledger[2761] allocator: op:0:0:2:Project), isOwning: true, size: 32768, references: 1, life: 13372865833009204..0, allocatorManager: [700, life: 13372864957931156..0] holds 1 buffers. 
              DrillBuf[3181], udle: [701 0..32768]
          ledger[2769] allocator: op:0:0:2:Project), isOwning: true, size: 4096, references: 1, life: 13372865833502205..0, allocatorManager: [708, life: 13372864960352194..0] holds 1 buffers. 
              DrillBuf[3189], udle: [709 0..4096]
          ledger[2741] allocator: op:0:0:2:Project), isOwning: true, size: 4096, references: 1, life: 13372865831092092..0, allocatorManager: [696, life: 13372864956764681..0] holds 1 buffers. 
              DrillBuf[3160], udle: [697 0..4096]
        reservations: 0
      
      
      Fragment 0:0
      
      [Error Id: f8d274e2-8119-495c-8a38-017c834f9931 on qa-node183.qa.lab:31010]
      
        (java.lang.IllegalStateException) Allocator[op:0:0:2:Project] closed with outstanding buffers allocated (6).
      Allocator(op:0:0:2:Project) 1000000/110592/434176/10000000000 (res/actual/peak/limit)
        child allocators: 0
        ledgers: 6
          ledger[2747] allocator: op:0:0:2:Project), isOwning: true, size: 32768, references: 1, life: 13372865831733586..0, allocatorManager: [694, life: 13372864956215117..0] holds 1 buffers. 
              DrillBuf[3165], udle: [694 0..32768]
          ledger[2756] allocator: op:0:0:2:Project), isOwning: true, size: 4096, references: 1, life: 13372865832378236..0, allocatorManager: [702, life: 13372864958396200..0] holds 1 buffers. 
              DrillBuf[3176], udle: [703 0..4096]
          ledger[2775] allocator: op:0:0:2:Project), isOwning: true, size: 32768, references: 1, life: 13372865833922897..0, allocatorManager: [706, life: 13372864959861722..0] holds 1 buffers. 
              DrillBuf[3196], udle: [707 0..32768]
          ledger[2761] allocator: op:0:0:2:Project), isOwning: true, size: 32768, references: 1, life: 13372865833009204..0, allocatorManager: [700, life: 13372864957931156..0] holds 1 buffers. 
              DrillBuf[3181], udle: [701 0..32768]
          ledger[2769] allocator: op:0:0:2:Project), isOwning: true, size: 4096, references: 1, life: 13372865833502205..0, allocatorManager: [708, life: 13372864960352194..0] holds 1 buffers. 
              DrillBuf[3189], udle: [709 0..4096]
          ledger[2741] allocator: op:0:0:2:Project), isOwning: true, size: 4096, references: 1, life: 13372865831092092..0, allocatorManager: [696, life: 13372864956764681..0] holds 1 buffers. 
              DrillBuf[3160], udle: [697 0..4096]
        reservations: 0
      
          org.apache.drill.exec.memory.BaseAllocator.close():486
          org.apache.drill.exec.ops.OperatorContextImpl.close():149
          org.apache.drill.exec.ops.FragmentContext.suppressingClose():422
          org.apache.drill.exec.ops.FragmentContext.close():411
          org.apache.drill.exec.work.fragment.FragmentExecutor.closeOutResources():318
          org.apache.drill.exec.work.fragment.FragmentExecutor.cleanup():155
          org.apache.drill.exec.work.fragment.FragmentExecutor.run():262
          org.apache.drill.common.SelfCleaningRunnable.run():38
          java.util.concurrent.ThreadPoolExecutor.runWorker():1142
          java.util.concurrent.ThreadPoolExecutor$Worker.run():617
          java.lang.Thread.run():745
      
      	at org.apache.drill.jdbc.impl.DrillCursor.nextRowInternally(DrillCursor.java:489)
      	at org.apache.drill.jdbc.impl.DrillCursor.next(DrillCursor.java:593)
      	at oadd.org.apache.calcite.avatica.AvaticaResultSet.next(AvaticaResultSet.java:215)
      	at org.apache.drill.jdbc.impl.DrillResultSetImpl.next(DrillResultSetImpl.java:140)
      	at org.apache.drill.test.framework.DrillTestJdbc.executeQuery(DrillTestJdbc.java:218)
      	at org.apache.drill.test.framework.DrillTestJdbc.run(DrillTestJdbc.java:101)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      	at java.lang.Thread.run(Thread.java:745)
      Caused by: oadd.org.apache.drill.common.exceptions.UserRemoteException: SYSTEM ERROR: IllegalStateException: Allocator[op:0:0:2:Project] closed with outstanding buffers allocated (6).
      Allocator(op:0:0:2:Project) 1000000/110592/434176/10000000000 (res/actual/peak/limit)
        child allocators: 0
        ledgers: 6
          ledger[2747] allocator: op:0:0:2:Project), isOwning: true, size: 32768, references: 1, life: 13372865831733586..0, allocatorManager: [694, life: 13372864956215117..0] holds 1 buffers. 
              DrillBuf[3165], udle: [694 0..32768]
          ledger[2756] allocator: op:0:0:2:Project), isOwning: true, size: 4096, references: 1, life: 13372865832378236..0, allocatorManager: [702, life: 13372864958396200..0] holds 1 buffers. 
              DrillBuf[3176], udle: [703 0..4096]
          ledger[2775] allocator: op:0:0:2:Project), isOwning: true, size: 32768, references: 1, life: 13372865833922897..0, allocatorManager: [706, life: 13372864959861722..0] holds 1 buffers. 
              DrillBuf[3196], udle: [707 0..32768]
          ledger[2761] allocator: op:0:0:2:Project), isOwning: true, size: 32768, references: 1, life: 13372865833009204..0, allocatorManager: [700, life: 13372864957931156..0] holds 1 buffers. 
              DrillBuf[3181], udle: [701 0..32768]
          ledger[2769] allocator: op:0:0:2:Project), isOwning: true, size: 4096, references: 1, life: 13372865833502205..0, allocatorManager: [708, life: 13372864960352194..0] holds 1 buffers. 
              DrillBuf[3189], udle: [709 0..4096]
          ledger[2741] allocator: op:0:0:2:Project), isOwning: true, size: 4096, references: 1, life: 13372865831092092..0, allocatorManager: [696, life: 13372864956764681..0] holds 1 buffers. 
              DrillBuf[3160], udle: [697 0..4096]
        reservations: 0
      
      
      Fragment 0:0
      
      [Error Id: f8d274e2-8119-495c-8a38-017c834f9931 on qa-node183.qa.lab:31010]
      
        (java.lang.IllegalStateException) Allocator[op:0:0:2:Project] closed with outstanding buffers allocated (6).
      Allocator(op:0:0:2:Project) 1000000/110592/434176/10000000000 (res/actual/peak/limit)
        child allocators: 0
        ledgers: 6
          ledger[2747] allocator: op:0:0:2:Project), isOwning: true, size: 32768, references: 1, life: 13372865831733586..0, allocatorManager: [694, life: 13372864956215117..0] holds 1 buffers. 
              DrillBuf[3165], udle: [694 0..32768]
          ledger[2756] allocator: op:0:0:2:Project), isOwning: true, size: 4096, references: 1, life: 13372865832378236..0, allocatorManager: [702, life: 13372864958396200..0] holds 1 buffers. 
              DrillBuf[3176], udle: [703 0..4096]
          ledger[2775] allocator: op:0:0:2:Project), isOwning: true, size: 32768, references: 1, life: 13372865833922897..0, allocatorManager: [706, life: 13372864959861722..0] holds 1 buffers. 
              DrillBuf[3196], udle: [707 0..32768]
          ledger[2761] allocator: op:0:0:2:Project), isOwning: true, size: 32768, references: 1, life: 13372865833009204..0, allocatorManager: [700, life: 13372864957931156..0] holds 1 buffers. 
              DrillBuf[3181], udle: [701 0..32768]
          ledger[2769] allocator: op:0:0:2:Project), isOwning: true, size: 4096, references: 1, life: 13372865833502205..0, allocatorManager: [708, life: 13372864960352194..0] holds 1 buffers. 
              DrillBuf[3189], udle: [709 0..4096]
          ledger[2741] allocator: op:0:0:2:Project), isOwning: true, size: 4096, references: 1, life: 13372865831092092..0, allocatorManager: [696, life: 13372864956764681..0] holds 1 buffers. 
              DrillBuf[3160], udle: [697 0..4096]
        reservations: 0
      
          org.apache.drill.exec.memory.BaseAllocator.close():486
          org.apache.drill.exec.ops.OperatorContextImpl.close():149
          org.apache.drill.exec.ops.FragmentContext.suppressingClose():422
          org.apache.drill.exec.ops.FragmentContext.close():411
          org.apache.drill.exec.work.fragment.FragmentExecutor.closeOutResources():318
          org.apache.drill.exec.work.fragment.FragmentExecutor.cleanup():155
          org.apache.drill.exec.work.fragment.FragmentExecutor.run():262
          org.apache.drill.common.SelfCleaningRunnable.run():38
          java.util.concurrent.ThreadPoolExecutor.runWorker():1142
          java.util.concurrent.ThreadPoolExecutor$Worker.run():617
          java.lang.Thread.run():745
      
      	at oadd.org.apache.drill.exec.rpc.user.QueryResultHandler.resultArrived(QueryResultHandler.java:123)
      	at oadd.org.apache.drill.exec.rpc.user.UserClient.handle(UserClient.java:343)
      	at oadd.org.apache.drill.exec.rpc.user.UserClient.handle(UserClient.java:88)
      	at oadd.org.apache.drill.exec.rpc.RpcBus$InboundHandler.decode(RpcBus.java:274)
      	at oadd.org.apache.drill.exec.rpc.RpcBus$InboundHandler.decode(RpcBus.java:244)
      	at oadd.io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:89)
      	at oadd.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339)
      	at oadd.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324)
      	at oadd.io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:254)
      	at oadd.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339)
      	at oadd.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324)
      	at oadd.io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103)
      	at oadd.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339)
      	at oadd.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324)
      	at oadd.io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:242)
      	at oadd.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339)
      	at oadd.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324)
      	at oadd.io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
      	at oadd.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339)
      	at oadd.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324)
      	at oadd.io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:847)
      	at oadd.io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:131)
      	at oadd.io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)
      	at oadd.io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)
      	at oadd.io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)
      	at oadd.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)
      	at oadd.io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:111)
      	... 1 more
      

      [1] https://github.com/mapr/drill-test-framework/tree/master/framework/resources/Functional/json/json_kvgenflatten

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                rkins Rahul Kumar Challapalli
              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated: