[
https://issues.apache.org/jira/browse/DRILL-3105?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14549324#comment-14549324
]
Khurram Faraaz commented on DRILL-3105:
---------------------------------------
Verified on rpm with commit id faec150598840c40827e6493992d81209aa936da. i
don't see the OOM any more on sqlline.
> OutOfMemoryError: GC overhead limit exceeded
> --------------------------------------------
>
> Key: DRILL-3105
> URL: https://issues.apache.org/jira/browse/DRILL-3105
> Project: Apache Drill
> Issue Type: Bug
> Components: Execution - Flow
> Affects Versions: 1.0.0
> Reporter: Khurram Faraaz
> Assignee: Chris Westin
> Fix For: 1.0.0
>
>
> On mapr-drill-1.0.0.31805-1.noarch.rpm we se OOM on sqlline prompt. Test was
> run on 4 node cluster on CentOS
> {code}
> [root@centos-01 ~]# cd /opt/mapr/drill/drill-1.0.0/bin/
> [root@centos-01 bin]# ./sqlline -u "jdbc:drill:schema=dfs.tmp"
> apache drill 1.0.0
> "a drill in the hand is better than two in the bush"
> 0: jdbc:drill:schema=dfs.tmp> select * from sys.drillbits;
> +-------------------+------------+---------------+------------+----------+
> | hostname | user_port | control_port | data_port | current |
> +-------------------+------------+---------------+------------+----------+
> | centos-01.qa.lab | 31010 | 31011 | 31012 | false |
> | centos-03.qa.lab | 31010 | 31011 | 31012 | false |
> | centos-02.qa.lab | 31010 | 31011 | 31012 | false |
> | centos-04.qa.lab | 31010 | 31011 | 31012 | true |
> +-------------------+------------+---------------+------------+----------+
> 4 rows selected (1.977 seconds)
> 0: jdbc:drill:schema=dfs.tmp> select * from sys.memory;
> +-------------------+------------+---------------+-------------+-----------------+---------------------+-------------+
> | hostname | user_port | heap_current | heap_max |
> direct_current | jvm_direct_current | direct_max |
> +-------------------+------------+---------------+-------------+-----------------+---------------------+-------------+
> | centos-04.qa.lab | 31010 | 316917688 | 4294967296 | 11798941
> | 100676587 | 8589934592 |
> | centos-03.qa.lab | 31010 | 132006832 | 4294967296 | 7750365
> | 50344939 | 8589934592 |
> | centos-02.qa.lab | 31010 | 328204288 | 4294967296 | 7750365
> | 50344939 | 8589934592 |
> | centos-01.qa.lab | 31010 | 350224384 | 4294967296 | 7750365
> | 50344939 | 8589934592 |
> +-------------------+------------+---------------+-------------+-----------------+---------------------+-------------+
> 4 rows selected (0.967 seconds)
> 0: jdbc:drill:schema=dfs.tmp> select key1, key2 from `twoKeyJsn.json`;
> java.lang.OutOfMemoryError: GC overhead limit exceeded
> at sun.misc.FloatingDecimal.dtoa(FloatingDecimal.java:678)
> at sun.misc.FloatingDecimal.<init>(FloatingDecimal.java:459)
> at java.lang.Double.toString(Double.java:196)
> at java.lang.Double.toString(Double.java:633)
> at java.lang.String.valueOf(String.java:2854)
> at sqlline.Rows$Row.<init>(Rows.java:157)
> at sqlline.IncrementalRows.hasNext(IncrementalRows.java:63)
> at
> sqlline.TableOutputFormat$ResizingRowsProvider.next(TableOutputFormat.java:77)
> at sqlline.TableOutputFormat.print(TableOutputFormat.java:106)
> at sqlline.SqlLine.print(SqlLine.java:1583)
> at sqlline.Commands.execute(Commands.java:852)
> at sqlline.Commands.sql(Commands.java:751)
> at sqlline.SqlLine.dispatch(SqlLine.java:738)
> at sqlline.SqlLine.begin(SqlLine.java:612)
> at sqlline.SqlLine.start(SqlLine.java:366)
> at sqlline.SqlLine.main(SqlLine.java:259)
> 0: jdbc:drill:schema=dfs.tmp>
> 0: jdbc:drill:schema=dfs.tmp> select * from `employee.csv`;
> Error: CONNECTION ERROR: Connection /10.10.100.201:48746 <-->
> /10.10.100.204:31010 (user client) closed unexpectedly.
> [Error Id: 7e0f3352-a412-49c9-83a1-7a3af324adb9 ] (state=,code=0)
> The SQL query just hung, and there was nothing written to drillbit.log, I had
> to hit Ctrl-C and then the OOM showed up on sqlline prompt.
> snippet from drillbit.log before query was Canceled
> {code}
> 2015-05-15 18:51:17,669 [2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:foreman] INFO
> o.a.d.e.s.schedule.BlockMapBuilder - Get block maps: Executed 1 out of 1
> using 1 threads. Time: 39ms total, 39.251707ms avg, 39ms max.
> 2015-05-15 18:51:17,669 [2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:foreman] INFO
> o.a.d.e.s.schedule.BlockMapBuilder - Get block maps: Executed 1 out of 1
> using 1 threads. Earliest start: 10.168000 μs, Latest start: 10.168000 μs,
> Average start: 10.168000 μs .
> 2015-05-15 18:51:17,746 [2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:foreman] INFO
> o.a.drill.exec.work.foreman.Foreman - State change requested. PENDING -->
> RUNNING
> 2015-05-15 18:51:17,793 [2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:frag:0:0] INFO
> o.a.d.e.w.fragment.FragmentExecutor -
> 2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:0:0: State change requested from
> AWAITING_ALLOCATION --> RUNNING for
> 2015-05-15 18:51:17,793 [2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:frag:0:0] INFO
> o.a.d.e.w.f.AbstractStatusReporter - State changed for
> 2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:0:0. New state: RUNNING
> 2015-05-15 18:51:18,054 [2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:frag:0:0] INFO
> o.a.drill.exec.vector.UInt4Vector - Realloc vector null. [16384] -> [32768]
> {code}
> snippet from drillbit.log after query was Canceled
> {code}
> 2015-05-15 18:56:19,938 [UserServer-1] INFO
> o.a.drill.exec.rpc.user.UserServer - RPC connection /10.10.100.204:31010 <-->
> /10.10.100.201:48746 (user client) timed out. Timeout was set to 30 seconds.
> Closing connection.
> 2015-05-15 18:56:19,941 [UserServer-1] INFO
> o.a.d.e.w.fragment.FragmentExecutor -
> 2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:0:0: State change requested from RUNNING
> --> FAILED for
> 2015-05-15 18:56:19,941 [UserServer-1] INFO
> o.a.drill.exec.work.foreman.Foreman - State change requested. RUNNING -->
> CANCELLATION_REQUESTED
> 2015-05-15 18:56:19,952 [UserServer-1] INFO
> o.a.d.e.w.fragment.FragmentExecutor -
> 2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:0:0: State change requested from FAILED
> --> FAILED for
> 2015-05-15 18:56:19,953 [BitServer-4] INFO
> o.a.d.e.w.fragment.FragmentExecutor -
> 2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:0:0: State change requested from FAILED
> --> CANCELLATION_REQUESTED for
> 2015-05-15 18:56:19,953 [BitServer-4] WARN
> o.a.d.e.w.fragment.FragmentExecutor - Ignoring unexpected state transition
> FAILED => CANCELLATION_REQUESTED.
> 2015-05-15 18:56:19,959 [UserServer-1] WARN
> o.a.d.exec.rpc.RpcExceptionHandler - Exception occurred with closed channel.
> Connection: /10.10.100.204:31010 <--> /10.10.100.201:48746 (user client)
> java.nio.channels.ClosedChannelException: null
> 2015-05-15 18:56:19,959 [UserServer-1] INFO
> o.a.d.e.w.fragment.FragmentExecutor -
> 2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:0:0: State change requested from FAILED
> --> FAILED for
> 2015-05-15 18:56:19,960 [UserServer-1] WARN
> o.a.d.exec.rpc.RpcExceptionHandler - Exception occurred with closed channel.
> Connection: /10.10.100.204:31010 <--> /10.10.100.201:48746 (user client)
> java.nio.channels.ClosedChannelException: null
> 2015-05-15 18:56:19,961 [UserServer-1] INFO
> o.a.d.e.w.fragment.FragmentExecutor -
> 2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:0:0: State change requested from FAILED
> --> FAILED for
> 2015-05-15 18:56:19,963 [UserServer-1] WARN
> o.a.d.exec.rpc.RpcExceptionHandler - Exception occurred with closed channel.
> Connection: /10.10.100.204:31010 <--> /10.10.100.201:48746 (user client)
> io.netty.handler.codec.EncoderException: RpcEncoder must produce at least one
> message.
> at
> io.netty.handler.codec.MessageToMessageEncoder.write(MessageToMessageEncoder.java:98)
> ~[netty-codec-4.0.27.Final.jar:4.0.27.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeWrite(AbstractChannelHandlerContext.java:705)
> [netty-transport-4.0.27.Final.jar:4.0.27.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.access$1900(AbstractChannelHandlerContext.java:32)
> [netty-transport-4.0.27.Final.jar:4.0.27.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext$AbstractWriteTask.write(AbstractChannelHandlerContext.java:980)
> [netty-transport-4.0.27.Final.jar:4.0.27.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext$WriteAndFlushTask.write(AbstractChannelHandlerContext.java:1032)
> [netty-transport-4.0.27.Final.jar:4.0.27.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext$AbstractWriteTask.run(AbstractChannelHandlerContext.java:965)
> [netty-transport-4.0.27.Final.jar:4.0.27.Final]
> at
> io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:357)
> [netty-common-4.0.27.Final.jar:4.0.27.Final]
> at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:254)
> [netty-transport-native-epoll-4.0.27.Final-linux-x86_64.jar:na]
> 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:744) [na:1.7.0_45]
> 2015-05-15 18:56:19,963 [UserServer-1] INFO
> o.a.d.e.w.fragment.FragmentExecutor -
> 2aa9bfd9-cbfd-8c6f-44aa-411a7aa34503:0:0: State change requested from FAILED
> --> FAILED for
> 2015-05-15 18:56:19,964 [UserServer-1] WARN
> o.a.d.exec.rpc.RpcExceptionHandler - Exception occurred with closed channel.
> Connection: /10.10.100.204:31010 <--> /10.10.100.201:48746 (user client)
> io.netty.handler.codec.EncoderException: RpcEncoder must produce at least one
> message.
> at
> io.netty.handler.codec.MessageToMessageEncoder.write(MessageToMessageEncoder.java:98)
> ~[netty-codec-4.0.27.Final.jar:4.0.27.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeWrite(AbstractChannelHandlerContext.java:705)
> [netty-transport-4.0.27.Final.jar:4.0.27.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.access$1900(AbstractChannelHandlerContext.java:32)
> [netty-transport-4.0.27.Final.jar:4.0.27.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext$AbstractWriteTask.write(AbstractChannelHandlerContext.java:980)
> [netty-transport-4.0.27.Final.jar:4.0.27.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext$WriteAndFlushTask.write(AbstractChannelHandlerContext.java:1032)
> [netty-transport-4.0.27.Final.jar:4.0.27.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext$AbstractWriteTask.run(AbstractChannelHandlerContext.java:965)
> [netty-transport-4.0.27.Final.jar:4.0.27.Final]
> at
> io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:357)
> [netty-common-4.0.27.Final.jar:4.0.27.Final]
> at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:254)
> [netty-transport-native-epoll-4.0.27.Final-linux-x86_64.jar:na]
> 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:744) [na:1.7.0_45]
> ~
> {code}
> The next query returned CONNECTION ERROR
> {code}
>
> 0: jdbc:drill:schema=dfs.tmp>
> 0: jdbc:drill:schema=dfs.tmp> select * from `employee.csv`;
> Error: CONNECTION ERROR: Connection /10.10.100.201:48746 <-->
> /10.10.100.204:31010 (user client) closed unexpectedly.
> [Error Id: 7e0f3352-a412-49c9-83a1-7a3af324adb9 ] (state=,code=0)
> {code}
> File size of file used in query is
> {code}
> [root@centos-04 logs]# hadoop fs -ls /tmp/twoKeyJsn.json
> -rwxr-xr-x 3 root root 888409136 2015-04-20 18:32 /tmp/twoKeyJsn.json
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
