[
https://issues.apache.org/jira/browse/DRILL-7449?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17016064#comment-17016064
]
benj commented on DRILL-7449:
-----------------------------
[~IhorHuzenko], please find in attachment (execution with leak from my local
machine in embedded 1.17 on xubuntu 18.04):
- [^embedded_FullJsonProfile.txt]
- [^embedded_sqlline.log.txt]
The Physical plan:
{noformat}
00-00 Screen : rowType = RecordType(VARCHAR(255) Fragment, BIGINT Number of
records written): rowcount = 5845417.0, cumulative cost = {7.07295457E7 rows,
7.424585516618018E8 cpu, 5.985707595E9 io, 4.7885656064E10 network, 4.6763336E7
memory}, id = 739
00-01 Project(Fragment=[$0], Number of records written=[$1]) : rowType =
RecordType(VARCHAR(255) Fragment, BIGINT Number of records written): rowcount =
5845417.0, cumulative cost = {7.0145004E7 rows, 7.418740099618018E8 cpu,
5.985707595E9 io, 4.7885656064E10 network, 4.6763336E7 memory}, id = 738
00-02 Writer : rowType = RecordType(VARCHAR(255) Fragment, BIGINT Number
of records written): rowcount = 5845417.0, cumulative cost = {6.4299587E7 rows,
7.301831759618018E8 cpu, 5.985707595E9 io, 4.7885656064E10 network, 4.6763336E7
memory}, id = 737
00-03 ProjectAllowDup(Domain=[$0]) : rowType = RecordType(ANY Domain):
rowcount = 5845417.0, cumulative cost = {5.845417E7 rows, 7.243377589618018E8
cpu, 5.985707595E9 io, 4.7885656064E10 network, 4.6763336E7 memory}, id = 736
00-04 Project(Domain=[$0]) : rowType = RecordType(ANY Domain):
rowcount = 5845417.0, cumulative cost = {5.2608753E7 rows, 7.184923419618018E8
cpu, 5.985707595E9 io, 4.7885656064E10 network, 4.6763336E7 memory}, id = 735
00-05 SingleMergeExchange(sort0=[0]) : rowType = RecordType(ANY
Domain): rowcount = 5845417.0, cumulative cost = {4.6763336E7 rows,
7.126469249618018E8 cpu, 5.985707595E9 io, 4.7885656064E10 network, 4.6763336E7
memory}, id = 734
01-01 OrderedMuxExchange(sort0=[0]) : rowType = RecordType(ANY
Domain): rowcount = 5845417.0, cumulative cost = {4.0917919E7 rows,
6.658835889618018E8 cpu, 5.985707595E9 io, 2.3942828032E10 network, 4.6763336E7
memory}, id = 733
02-01 SelectionVectorRemover : rowType = RecordType(ANY
Domain): rowcount = 5845417.0, cumulative cost = {3.5072502E7 rows,
6.600381719618018E8 cpu, 5.985707595E9 io, 2.3942828032E10 network, 4.6763336E7
memory}, id = 732
02-02 Sort(sort0=[$0], dir0=[ASC]) : rowType =
RecordType(ANY Domain): rowcount = 5845417.0, cumulative cost = {2.9227085E7
rows, 6.541927549618018E8 cpu, 5.985707595E9 io, 2.3942828032E10 network,
4.6763336E7 memory}, id = 731
02-03 HashToRandomExchange(dist0=[[$0]]) : rowType =
RecordType(ANY Domain): rowcount = 5845417.0, cumulative cost = {2.3381668E7
rows, 1.28599174E8 cpu, 5.985707595E9 io, 2.3942828032E10 network, 0.0 memory},
id = 730
03-01 Project(Domain=[ITEM($0, 'host')]) : rowType =
RecordType(ANY Domain): rowcount = 5845417.0, cumulative cost = {1.7536251E7
rows, 3.5072502E7 cpu, 5.985707595E9 io, 0.0 network, 0.0 memory}, id = 729
03-02 Project(parsed=[PARSE_URL($0)]) : rowType =
RecordType(ANY parsed): rowcount = 5845417.0, cumulative cost = {1.1690834E7
rows, 2.9227085E7 cpu, 5.985707595E9 io, 0.0 network, 0.0 memory}, id = 728
03-03 Scan(table=[[dfs, tmp,
fbingredagg.bigcopy.json]], groupscan=[EasyGroupScan
[selectionRoot=file:/tmp/fbingredagg.bigcopy.json, numFiles=1, columns=[`Url`],
files=[file:/tmp/fbingredagg.bigcopy.json], schema=null]]) : rowType =
RecordType(ANY Url): rowcount = 5845417.0, cumulative cost = {5845417.0 rows,
5845417.0 cpu, 5.985707595E9 io, 0.0 network, 0.0 memory}, id = 727
{noformat}
And the Operator profile
Note that Rows are 8 695 808 although in the file there is 8 999 940 rows
{noformat}
Operator ID Type Avg Setup Time Max Setup Time Avg Process Time
Max Process Time Min Wait Time Avg Wait Time Max Wait Time %
Fragment Time % Query Time Rows Avg Peak Memory Max Peak Memory
00-xx-00 SCREEN 0,000s 0,000s 0,000s 0,000s 0,000s 0,000s 0,000s
0,94% 0,00% 0 - -
00-xx-01 PROJECT 0,000s 0,000s 0,000s 0,000s 0,000s 0,000s 0,000s
2,37% 0,00% 0 - -
00-xx-02 PARQUET_WRITER 0,000s 0,000s 0,000s 0,000s 0,000s 0,000s
0,000s 6,08% 0,00% 0 - -
00-xx-03 PROJECT_ALLOW_DUP 0,000s 0,000s 0,000s 0,000s 0,000s
0,000s 0,000s 16,61% 0,00% 0 52KB 52KB
00-xx-04 PROJECT 0,001s 0,001s 0,000s 0,000s 0,000s 0,000s 0,000s
35,03% 0,00% 0 52KB 52KB
00-xx-05 MERGING_RECEIVER 0,000s 0,000s 0,000s 0,000s 40,382s
40,382s 40,382s 38,96% 0,00% 0 52KB 52KB
01-xx-00 SINGLE_SENDER 0,000s 0,000s 0,000s 0,000s 0,001s 0,001s
0,001s 27,14% 0,00% 0 - -
01-xx-01 MERGING_RECEIVER 0,000s 0,000s 0,000s 0,000s 40,390s
40,390s 40,390s 72,86% 0,00% 0 52KB 52KB
02-xx-00 SINGLE_SENDER 0,000s 0,000s 0,000s 0,000s 0,000s 0,000s
0,000s 0,03% 0,00% 0 - -
02-xx-01 SELECTION_VECTOR_REMOVER 0,000s 0,000s 0,000s 0,000s
0,000s 0,000s 0,000s 0,02% 0,00% 0 52KB 52KB
02-xx-02 EXTERNAL_SORT 0,000s 0,000s 0,151s 0,204s 0,000s 0,000s
0,000s 90,81% 2,46% 8 999 940 63MB 78MB
02-xx-03 UNORDERED_RECEIVER 0,000s 0,000s 0,015s 0,021s 40,116s
40,174s 40,206s 9,14% 0,25% 8 999 940 64KB 64KB
03-xx-00 JSON_SUB_SCAN 0,000s 0,000s 9,860s 19,691s 0,440s 1,094s
1,749s 54,79% 53,30% 17 391 616 3MB 6MB
03-xx-01 PROJECT 0,001s 0,001s 0,124s 0,124s 0,000s 0,000s 0,000s
0,34% 0,34% 8 695 808 292KB 292KB
03-xx-02 PROJECT 0,001s 0,001s 16,149s 16,149s 0,000s 0,000s 0,000s
44,87% 43,65% 8 695 808 2MB 2MB
{noformat}
hoping it would help
> memory leak parse_url function
> ------------------------------
>
> Key: DRILL-7449
> URL: https://issues.apache.org/jira/browse/DRILL-7449
> Project: Apache Drill
> Issue Type: Bug
> Components: Functions - Drill
> Affects Versions: 1.16.0
> Reporter: benj
> Assignee: Igor Guzenko
> Priority: Major
> Attachments: embedded_FullJsonProfile.txt, embedded_sqlline.log.txt
>
>
> Requests with *parse_url* works well when the number of treated rows is low
> but produce memory leak when number of rows grows (~ between 500 000 and 1
> million) (and for certain number of row sometimes the request works and
> sometimes it failed with memory leaks)
> Extract from dataset tested:
> {noformat}
> {"Attributable":true,"Description":"Website has been identified as malicious
> by
> Bing","FirstReportedDateTime":"2018-03-12T18:49:38Z","IndicatorExpirationDateTime":"2018-04-11T23:33:13Z","IndicatorProvider":"Bing","IndicatorThreatType":"MaliciousUrl","IsPartnerShareable":true,"IsProductLicensed":true,"LastReportedDateTime":"2018-03-12T18:49:38Z","NetworkDestinationAsn":15169,"NetworkDestinationIPv4":"172.217.8.193","NetworkDestinationPort":80,"Tags":["us"],"ThreatDetectionProduct":"ES","TLPLevel":"Amber","Url":"http://pasuruanbloggers.blogspot.ru/2012/12/beginilah-cara-orang-jepang-berpacaran.html","Version":1.5}
> {"Attributable":true,"Description":"Website has been identified as malicious
> by
> Bing","FirstReportedDateTime":"2018-03-12T18:14:51Z","IndicatorExpirationDateTime":"2018-04-11T23:33:13Z","IndicatorProvider":"Bing","IndicatorThreatType":"MaliciousUrl","IsPartnerShareable":true,"IsProductLicensed":true,"LastReportedDateTime":"2018-03-12T18:14:51Z","NetworkDestinationAsn":15169,"NetworkDestinationIPv4":"216.58.192.193","NetworkDestinationPort":80,"Tags":["us"],"ThreatDetectionProduct":"ES","TLPLevel":"Amber","Url":"http://pasuruanbloggers.blogspot.ru/2012/12/cara-membuat-widget-slideshow-postingan.html","Version":1.5}
> {noformat}
> Request tested:
> {code:sql}
> ALTER SESSION SET `store.format`='parquet';
> ALTER SESSION SET `store.parquet.use_new_reader` = true;
> ALTER SESSION SET `store.parquet.compression` = 'snappy';
> ALTER SESSION SET `drill.exec.functions.cast_empty_string_to_null`= true;
> ALTER SESSION SET `store.json.all_text_mode` = true;
> ALTER SESSION SET `exec.enable_union_type` = true;
> ALTER SESSION SET `store.json.all_text_mode` = true;
> CREATE TABLE dfs.test.`output_pqt` AS
> (
> SELECT R.parsed.host AS Domain
> FROM (
> SELECT parse_url(T.Url) AS parsed
> FROM dfs.test.`file.json` AS T
> ) AS R
> ORDER BY Domain
> );
> {code}
>
> Result when memory leak:
> {noformat}
> Error: SYSTEM ERROR: IllegalStateException: Memory was leaked by query.
> Memory leaked: (256)
> Allocator(frag:3:0) 3000000/256/9337280/30000000000 (res/actual/peak/limit)
> Fragment 3:0
> Please, refer to logs for more information.
> [Error Id: 3ffa5b43-0dde-4518-bb5a-ea3aab97f3d4 on servor01:31010]
> (java.lang.IllegalStateException) Memory was leaked by query. Memory
> leaked: (256)
> Allocator(frag:3:0) 3000000/256/9337280/30000000000 (res/actual/peak/limit)
> org.apache.drill.exec.memory.BaseAllocator.close():520
> org.apache.drill.exec.ops.FragmentContextImpl.suppressingClose():552
> org.apache.drill.exec.ops.FragmentContextImpl.close():546
>
> org.apache.drill.exec.work.fragment.FragmentExecutor.closeOutResources():386
> org.apache.drill.exec.work.fragment.FragmentExecutor.cleanup():214
> org.apache.drill.exec.work.fragment.FragmentExecutor.run():329
> org.apache.drill.common.SelfCleaningRunnable.run():38
> java.util.concurrent.ThreadPoolExecutor.runWorker():1149
> java.util.concurrent.ThreadPoolExecutor$Worker.run():624
> java.lang.Thread.run():748 (state=,code=0)
> java.sql.SQLException: SYSTEM ERROR: IllegalStateException: Memory was leaked
> by query. Memory leaked: (256)
> Allocator(frag:3:0) 3000000/256/9337280/30000000000 (res/actual/peak/limit)
> Fragment 3:0
> Please, refer to logs for more information.
> [Error Id: 3ffa5b43-0dde-4518-bb5a-ea3aab97f3d4 on servor01:31010]
> (java.lang.IllegalStateException) Memory was leaked by query. Memory
> leaked: (256)
> Allocator(frag:3:0) 3000000/256/9337280/30000000000 (res/actual/peak/limit)
> org.apache.drill.exec.memory.BaseAllocator.close():520
> org.apache.drill.exec.ops.FragmentContextImpl.suppressingClose():552
> org.apache.drill.exec.ops.FragmentContextImpl.close():546
>
> org.apache.drill.exec.work.fragment.FragmentExecutor.closeOutResources():386
> org.apache.drill.exec.work.fragment.FragmentExecutor.cleanup():214
> org.apache.drill.exec.work.fragment.FragmentExecutor.run():329
> org.apache.drill.common.SelfCleaningRunnable.run():38
> java.util.concurrent.ThreadPoolExecutor.runWorker():1149
> java.util.concurrent.ThreadPoolExecutor$Worker.run():624
> java.lang.Thread.run():748
> at
> org.apache.drill.jdbc.impl.DrillCursor.nextRowInternally(DrillCursor.java:538)
> at
> org.apache.drill.jdbc.impl.DrillCursor.loadInitialSchema(DrillCursor.java:610)
> at
> org.apache.drill.jdbc.impl.DrillResultSetImpl.execute(DrillResultSetImpl.java:1278)
> at
> org.apache.drill.jdbc.impl.DrillResultSetImpl.execute(DrillResultSetImpl.java:58)
> at
> org.apache.calcite.avatica.AvaticaConnection$1.execute(AvaticaConnection.java:667)
> at
> org.apache.drill.jdbc.impl.DrillMetaImpl.prepareAndExecute(DrillMetaImpl.java:1107)
> at
> org.apache.drill.jdbc.impl.DrillMetaImpl.prepareAndExecute(DrillMetaImpl.java:1118)
> at
> org.apache.calcite.avatica.AvaticaConnection.prepareAndExecuteInternal(AvaticaConnection.java:675)
> at
> org.apache.drill.jdbc.impl.DrillConnectionImpl.prepareAndExecuteInternal(DrillConnectionImpl.java:200)
> at
> org.apache.calcite.avatica.AvaticaStatement.executeInternal(AvaticaStatement.java:156)
> at
> org.apache.calcite.avatica.AvaticaStatement.execute(AvaticaStatement.java:217)
> at sqlline.Commands.execute(Commands.java:971)
> at sqlline.Commands.sql(Commands.java:906)
> at sqlline.SqlLine.dispatch(SqlLine.java:740)
> at sqlline.SqlLine.runCommands(SqlLine.java:1691)
> at sqlline.Commands.run(Commands.java:1513)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> sqlline.ReflectiveCommandHandler.execute(ReflectiveCommandHandler.java:38)
> at sqlline.SqlLine.dispatch(SqlLine.java:736)
> at sqlline.SqlLine.initArgs(SqlLine.java:475)
> at sqlline.SqlLine.begin(SqlLine.java:531)
> at sqlline.SqlLine.start(SqlLine.java:270)
> at sqlline.SqlLine.main(SqlLine.java:201)
> Caused by: org.apache.drill.common.exceptions.UserRemoteException: SYSTEM
> ERROR: IllegalStateException: Memory was leaked by query. Memory leaked: (256)
> Allocator(frag:3:0) 3000000/256/9337280/30000000000 (res/actual/peak/limit)
> Fragment 3:0
> Please, refer to logs for more information.
> [Error Id: 3ffa5b43-0dde-4518-bb5a-ea3aab97f3d4 on servor01:31010]
> (java.lang.IllegalStateException) Memory was leaked by query. Memory
> leaked: (256)
> Allocator(frag:3:0) 3000000/256/9337280/30000000000 (res/actual/peak/limit)
> org.apache.drill.exec.memory.BaseAllocator.close():520
> org.apache.drill.exec.ops.FragmentContextImpl.suppressingClose():552
> org.apache.drill.exec.ops.FragmentContextImpl.close():546
>
> org.apache.drill.exec.work.fragment.FragmentExecutor.closeOutResources():386
> org.apache.drill.exec.work.fragment.FragmentExecutor.cleanup():214
> org.apache.drill.exec.work.fragment.FragmentExecutor.run():329
> org.apache.drill.common.SelfCleaningRunnable.run():38
> java.util.concurrent.ThreadPoolExecutor.runWorker():1149
> java.util.concurrent.ThreadPoolExecutor$Worker.run():624
> java.lang.Thread.run():748
> at
> org.apache.drill.exec.rpc.user.QueryResultHandler.resultArrived(QueryResultHandler.java:123)
> at org.apache.drill.exec.rpc.user.UserClient.handle(UserClient.java:422)
> at org.apache.drill.exec.rpc.user.UserClient.handle(UserClient.java:96)
> at
> org.apache.drill.exec.rpc.RpcBus$InboundHandler.decode(RpcBus.java:273)
> at
> org.apache.drill.exec.rpc.RpcBus$InboundHandler.decode(RpcBus.java:243)
> at
> io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:88)
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:356)
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)
> at
> io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:335)
> at
> io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:287)
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:356)
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)
> at
> io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:335)
> at
> io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:356)
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)
> at
> io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:335)
> at
> io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:312)
> at
> io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:286)
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:356)
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)
> at
> io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:335)
> at
> io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:356)
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)
> at
> io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:335)
> at
> io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1294)
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:356)
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)
> at
> io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:911)
> at
> io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:131)
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645)
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:580)
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:497)
> at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459)
> at
> io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:131)
> at java.lang.Thread.run(Thread.java:748)
> Caused by: java.lang.IllegalStateException: Memory was leaked by query.
> Memory leaked: (256)
> Allocator(frag:3:0) 3000000/256/9337280/30000000000 (res/actual/peak/limit)
> at
> org.apache.drill.exec.memory.BaseAllocator.close(BaseAllocator.java:520)
> at
> org.apache.drill.exec.ops.FragmentContextImpl.suppressingClose(FragmentContextImpl.java:552)
> at
> org.apache.drill.exec.ops.FragmentContextImpl.close(FragmentContextImpl.java:546)
> at
> org.apache.drill.exec.work.fragment.FragmentExecutor.closeOutResources(FragmentExecutor.java:386)
> at
> org.apache.drill.exec.work.fragment.FragmentExecutor.cleanup(FragmentExecutor.java:214)
> at
> org.apache.drill.exec.work.fragment.FragmentExecutor.run(FragmentExecutor.java:329)
> at
> org.apache.drill.common.SelfCleaningRunnable.run(SelfCleaningRunnable.java:38)
> at .......(:0
> {noformat}
> Note that same request including some other field and excluding use of
> _parse_url_ works perfectly well.
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
