You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@drill.apache.org by Kunal Khatua <kk...@mapr.com> on 2017/03/02 01:54:31 UTC

Re: Explain Plan for Parquet data is taking a lot of timre

Hi Jeena


The JSON profile does not reveal much about why the planning time took so long, but only give you information from the physical plan and when the planning approximately completed (7+min for 2node; 15+min for 5node).

Drillbit logs, however, will give you more information. For this, you'll need to look in the log for with information like


2017-02-23 14:00:54,609 [27513143-8718-7a47-a2d4-06850755568a:foreman] DEBUG o.a.d.e.p.s.h.DefaultSqlHandler - VOLCANO:Physical Planning (49588ms):

You might need to enable your logback.xml to pop out this information (by enabling DEBUG level logging for these classes).
These are the recommended loggers you can enable DEBUG for:
org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler
org.apache.drill.exec.work.foreman.Foreman


You can share the drillbit log file with these as a run thereafter.


Also, Your profile JSONs indicate that you have a fairly slow underlying filesystem.


I'm seeing an average of

3m45s to read 945K rows (2 node setup)

and

2m25s to read 1.5M rows (5node setup)


Your 2node setup shows 6 fragments processing 29 batches; while 5node setup shows 15 fragments processing 46 batches. For the number of rows, the amount of time spent is very high, which makes me believe that your filesystem (Oracle Cloud Storage service) is itself quite slow.

For speeding up execution, you can try changing the planner.width.max_per_node to a higher value (like the number of cores on the node). This should increase parallelization and the utilization of all the cores by Drill.


Kunal Khatua

Engineering

[MapR]<http://www.mapr.com/>

www.mapr.com<http://www.mapr.com/>

________________________________
From: Jeena Vinod <je...@oracle.com>
Sent: Tuesday, February 28, 2017 12:24:52 PM
To: user@drill.apache.org
Subject: RE: Explain Plan for Parquet data is taking a lot of timre

Kindly let know if there are any pointers on how to improve response time for parquet data here.

Regards
Jeena

-----Original Message-----
From: Jeena Vinod
Sent: Tuesday, February 28, 2017 4:25 AM
To: user@drill.apache.org
Subject: RE: Explain Plan for Parquet data is taking a lot of timre

Hi,

I have 2 Drill 1.9 installations. One is a 5 node 32GB cluster and other is a 2 node 16GB cluster. And I am running the same query in both the places.
select * from `testdata` where <condition> limit 100; testdata is 1GB uncompressed parquet data.

The query response time is found as below:
2 node cluster - 13min
5 node cluster - 19min

I was expecting 5 node cluster to be faster, but the results say otherwise.
In the query profile, as expected, 5 node cluster has more minor fragments, but still the scan time is higher. Attached the json profile for both.
Is this in anyway related to the max batches/max records for row group scan?

Any suggestions on how we can get better response time in the 5 node cluster is appreciated.

Regards
Jeena

-----Original Message-----
From: Jeena Vinod
Sent: Sunday, February 26, 2017 2:22 AM
To: user@drill.apache.org
Subject: RE: Explain Plan for Parquet data is taking a lot of timre

Please find attached the full JSON profile.

Regards
Jeena

-----Original Message-----
From: Padma Penumarthy [mailto:ppenumarthy@mapr.com]
Sent: Saturday, February 25, 2017 3:31 AM
To: user@drill.apache.org
Subject: Re: Explain Plan for Parquet data is taking a lot of timre

Yes, please do send the JSON profile.

Thanks,
Padma

> On Feb 24, 2017, at 1:56 PM, Jeena Vinod <je...@oracle.com> wrote:
>
> Thanks for the suggestions.
>
> I did run REFRESH TABLE METADATA command on this path before firing select query.
>
> In Drill 1.9, there is an improvement in performance. I have 1.9 setup on a 2 node 16GB cluster and here select * with limit 100 is taking less time than 1.8, though the number of rows in ParquetGroupScan remains unchanged. Select query is taking around 8 minutes and explain plan took around 7 minutes. Also in the Web console profile, the query stays in the STARTING status for almost 7 minutes.
>
> Query Plan for 1.9:
> 00-00    Screen : rowType = RecordType(ANY *): rowcount = 100.0, cumulative cost = {32810.0 rows, 33110.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1721
> 00-01      Project(*=[$0]) : rowType = RecordType(ANY *): rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1720
> 00-02        SelectionVectorRemover : rowType = (DrillRecordRow[*]): rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1719
> 00-03          Limit(fetch=[100]) : rowType = (DrillRecordRow[*]): rowcount = 100.0, cumulative cost = {32700.0 rows, 33000.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1718
> 00-04            Scan(groupscan=[ParquetGroupScan [entries=[ReadEntryWithPath [path=/testdata/part-r-00000-097f7399-7bfb-4e93-b883-3348655fc658.parquet]], selectionRoot=/testdata, numFiles=1, usedMetadataFile=true, cacheFileRoot=/testdata, columns=[`*`]]]) : rowType = (DrillRecordRow[*]): rowcount = 32600.0, cumulative cost = {32600.0 rows, 32600.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1717
>
> And from the query profile, it looks like the most time is spent in PARQUET_ROW_GROUP_SCAN. I can attach the full JSON profile if it helps.
>
> Can there be further improvement in performance with 1.9?
>
> Regards
> Jeena
>
>
> -----Original Message-----
> From: Padma Penumarthy [mailto:ppenumarthy@mapr.com]
> Sent: Friday, February 24, 2017 11:22 PM
> To: user@drill.apache.org
> Subject: Re: Explain Plan for Parquet data is taking a lot of timre
>
> Yes, limit is pushed down to parquet reader in 1.9. But, that will not help with planning time.
> It is definitely worth trying with 1.9 though.
>
> Thanks,
> Padma
>
>
>> On Feb 24, 2017, at 7:26 AM, Andries Engelbrecht <ae...@mapr.com> wrote:
>>
>> Looks like the metadata cache is being used  "usedMetadataFile=true, ". But to be sure did you perform a REFRESH TABLE METADATA <path to table> on the parquet data?
>>
>>
>> However it looks like it is reading a full batch " rowcount = 32600.0, cumulative cost = {32600.0 rows, 32600.0"
>>
>>
>> Didn't the limit operator get pushed down to the parquet reader in 1.9?
>>
>> Perhaps try 1.9 and see if in the ParquetGroupScan the number of rows gets reduced to 100.
>>
>>
>> Can you look in the query profile where time is spend, also how long it takes before the query starts to run in the WebUI profile.
>>
>>
>> Best Regards
>>
>>
>> Andries Engelbrecht
>>
>>
>> Senior Solutions Architect
>>
>> MapR Alliances and Channels Engineering
>>
>>
>> aengelbrecht@mapr.com
>>
>>
>> [1483990071965_mapr-logo-signature.png]
>>
>> ________________________________
>> From: Jinfeng Ni <jn...@apache.org>
>> Sent: Thursday, February 23, 2017 4:53:34 PM
>> To: user
>> Subject: Re: Explain Plan for Parquet data is taking a lot of timre
>>
>> The reason the plan shows only one single parquet file is because
>> "LIMIT 100" is applied and filter out the rest of them.
>>
>> Agreed that parquet metadata caching might help reduce planning time,
>> when there are large number of parquet files.
>>
>> On Thu, Feb 23, 2017 at 4:44 PM, rahul challapalli
>> <ch...@gmail.com> wrote:
>>> You said there are 2144 parquet files but the plan suggests that you
>>> only have a single parquet file. In any case its a long time to plan the query.
>>> Did you try the metadata caching feature [1]?
>>>
>>> Also how many rowgroups and columns are present in the parquet file?
>>>
>>> [1]
>>> https://drill.apache.org/docs/optimizing-parquet-metadata-reading/
>>>
>>> - Rahul
>>>
>>> On Thu, Feb 23, 2017 at 4:24 PM, Jeena Vinod <je...@oracle.com> wrote:
>>>
>>>> Hi,
>>>>
>>>>
>>>>
>>>> Drill is taking 23 minutes for a simple select * query with limit
>>>> 100 on 1GB uncompressed parquet data. EXPLAIN PLAN for this query
>>>> is also taking that long(~23 minutes).
>>>>
>>>> Query: select * from <plugin>.root.`testdata` limit 100;
>>>>
>>>> Query  Plan:
>>>>
>>>> 00-00    Screen : rowType = RecordType(ANY *): rowcount = 100.0,
>>>> cumulative cost = {32810.0 rows, 33110.0 cpu, 0.0 io, 0.0 network,
>>>> 0.0 memory}, id = 1429
>>>>
>>>> 00-01      Project(*=[$0]) : rowType = RecordType(ANY *): rowcount =
>>>> 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0
>>>> network,
>>>> 0.0 memory}, id = 1428
>>>>
>>>> 00-02        SelectionVectorRemover : rowType = (DrillRecordRow[*]):
>>>> rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0
>>>> io, 0.0 network, 0.0 memory}, id = 1427
>>>>
>>>> 00-03          Limit(fetch=[100]) : rowType = (DrillRecordRow[*]):
>>>> rowcount = 100.0, cumulative cost = {32700.0 rows, 33000.0 cpu, 0.0
>>>> io, 0.0 network, 0.0 memory}, id = 1426
>>>>
>>>> 00-04            Scan(groupscan=[ParquetGroupScan
>>>> [entries=[ReadEntryWithPath [path=/testdata/part-r-00000-
>>>> 097f7399-7bfb-4e93-b883-3348655fc658.parquet]],
>>>> selectionRoot=/testdata, numFiles=1, usedMetadataFile=true,
>>>> cacheFileRoot=/testdata,
>>>> columns=[`*`]]]) : rowType = (DrillRecordRow[*]): rowcount =
>>>> 32600.0, cumulative cost = {32600.0 rows, 32600.0 cpu, 0.0 io, 0.0
>>>> network, 0.0 memory}, id = 1425
>>>>
>>>>
>>>>
>>>> I am using Drill1.8 and it is setup on 5 node 32GB cluster and the
>>>> data is in Oracle Storage Cloud Service. When I run the same query
>>>> on 1GB TSV file in this location it is taking only 38 seconds .
>>>>
>>>> Also testdata contains around 2144 .parquet files each around 500KB.
>>>>
>>>>
>>>>
>>>> Is there any additional configuration required for parquet?
>>>>
>>>> Kindly suggest how to improve the response time here.
>>>>
>>>>
>>>>
>>>> Regards
>>>> Jeena
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>


Re: Explain Plan for Parquet data is taking a lot of timre

Posted by rahul challapalli <ch...@gmail.com>.
For explanation regarding why we are rebuilding the metadata cache, take a
look at Padma's previous email. Most likely, there is a data change in the
folder. If not we should refresh the metadata cache and its a bug.

Drill currently does not do incremental metadata refreshes. Now lets say
you have a table "transactions" (with 100 partitions) and you added a new
partition to the "transaction" folder. Drill refreshes the metadata cache
for all the partitions (even though we only added 1 partition and nothing
has changed in the remaining partitions) automatically for the subsequent
query. This might explain why its taking a long time.

- Rahul

On Mon, Mar 6, 2017 at 9:24 AM, Chetan Kothari <ch...@oracle.com>
wrote:

> Hi All
>
>
>
> Any inputs on this?
>
>
>
> Why creating metadata files recursively should took 1457445 ms when
> refresh metadata on this path is already done?
>
>
>
> Regards
>
> Chetan
>
>
>
>               - -----Original Message-----
> From: Jeena Vinod
> Sent: Sunday, March 5, 2017 10:44 PM
> To: user@drill.apache.org
> Subject: RE: Explain Plan for Parquet data is taking a lot of timre
>
>
>
> Re- attaching the log file as zip file.
>
>
>
> Regards
>
> Jeena
>
>
>
> -----Original Message-----
>
> From: Jeena Vinod
>
> Sent: Sunday, March 05, 2017 9:23 PM
>
> To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org
>
> Subject: RE: Explain Plan for Parquet data is taking a lot of timre
>
>
>
> Hi Kunal,
>
>
>
> Thanks for the response.
>
> Attaching the log with DEBUG enabled for the mentioned loggers. I had to
> trim the log for the query, since this mailer allows max 1MB.
>
>
>
> From the log files, the below step seems to be taking the most time. Since
> refresh metadata on this path is already done, I am unsure what this means.
>
>       -Creating metadata files recursively took 1457445 ms
>
>
>
> Also I have 4 core nodes and the planner.width.max_per_node value is
> currently 3.
>
> I tried with values 6 and 8, but did not see significant improvement in
> response time. How do we get the optimal value for this property on a
> cluster?
>
>
>
> Regards
>
> Jeena
>
>
>
> -----Original Message-----
>
> From: Kunal Khatua [mailto:kkhatua@mapr.com]
>
> Sent: Thursday, March 02, 2017 7:25 AM
>
> To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org
>
> Subject: Re: Explain Plan for Parquet data is taking a lot of timre
>
>
>
> Hi Jeena
>
>
>
>
>
> The JSON profile does not reveal much about why the planning time took so
> long, but only give you information from the physical plan and when the
> planning approximately completed (7+min for 2node; 15+min for 5node).
>
>
>
> Drillbit logs, however, will give you more information. For this, you'll
> need to look in the log for with information like
>
>
>
>
>
> 2017-02-23 14:00:54,609 [27513143-8718-7a47-a2d4-06850755568a:foreman]
> DEBUG o.a.d.e.p.s.h.DefaultSqlHandler - VOLCANO:Physical Planning
> (49588ms):
>
>
>
> You might need to enable your logback.xml to pop out this information (by
> enabling DEBUG level logging for these classes).
>
> These are the recommended loggers you can enable DEBUG for:
>
> org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler
>
> org.apache.drill.exec.work.foreman.Foreman
>
>
>
>
>
> You can share the drillbit log file with these as a run thereafter.
>
>
>
>
>
> Also, Your profile JSONs indicate that you have a fairly slow underlying
> filesystem.
>
>
>
>
>
> I'm seeing an average of
>
>
>
> 3m45s to read 945K rows (2 node setup)
>
>
>
> and
>
>
>
> 2m25s to read 1.5M rows (5node setup)
>
>
>
>
>
> Your 2node setup shows 6 fragments processing 29 batches; while 5node
> setup shows 15 fragments processing 46 batches. For the number of rows, the
> amount of time spent is very high, which makes me believe that your
> filesystem (Oracle Cloud Storage service) is itself quite slow.
>
>
>
> For speeding up execution, you can try changing the
> planner.width.max_per_node to a higher value (like the number of cores on
> the node). This should increase parallelization and the utilization of all
> the cores by Drill.
>
>
>
>
>
> Kunal Khatua
>
>
>
> Engineering
>
>
>
> [MapR]<http://www.mapr.com/>
>
>
>
> HYPERLINK "http://www.mapr.com%3chttp:/www.mapr.com/"www.mapr.com<http
> ://www.mapr.com/>
>
>
>
> ________________________________
>
> From: Jeena Vinod <HYPERLINK "mailto:jeena.vinod@oracle.com"
> jeena.vinod@oracle.com>
>
> Sent: Tuesday, February 28, 2017 12:24:52 PM
>
> To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org
>
> Subject: RE: Explain Plan for Parquet data is taking a lot of timre
>
>
>
> Kindly let know if there are any pointers on how to improve response time
> for parquet data here.
>
>
>
> Regards
>
> Jeena
>
>
>
> -----Original Message-----
>
> From: Jeena Vinod
>
> Sent: Tuesday, February 28, 2017 4:25 AM
>
> To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org
>
> Subject: RE: Explain Plan for Parquet data is taking a lot of timre
>
>
>
> Hi,
>
>
>
> I have 2 Drill 1.9 installations. One is a 5 node 32GB cluster and other
> is a 2 node 16GB cluster. And I am running the same query in both the
> places.
>
> select * from `testdata` where <condition> limit 100; testdata is 1GB
> uncompressed parquet data.
>
>
>
> The query response time is found as below:
>
> 2 node cluster - 13min
>
> 5 node cluster - 19min
>
>
>
> I was expecting 5 node cluster to be faster, but the results say otherwise.
>
> In the query profile, as expected, 5 node cluster has more minor
> fragments, but still the scan time is higher. Attached the json profile for
> both.
>
> Is this in anyway related to the max batches/max records for row group
> scan?
>
>
>
> Any suggestions on how we can get better response time in the 5 node
> cluster is appreciated.
>
>
>
> Regards
>
> Jeena
>
>
>
> -----Original Message-----
>
> From: Jeena Vinod
>
> Sent: Sunday, February 26, 2017 2:22 AM
>
> To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org
>
> Subject: RE: Explain Plan for Parquet data is taking a lot of timre
>
>
>
> Please find attached the full JSON profile.
>
>
>
> Regards
>
> Jeena
>
>
>
> -----Original Message-----
>
> From: Padma Penumarthy [mailto:ppenumarthy@mapr.com]
>
> Sent: Saturday, February 25, 2017 3:31 AM
>
> To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org
>
> Subject: Re: Explain Plan for Parquet data is taking a lot of timre
>
>
>
> Yes, please do send the JSON profile.
>
>
>
> Thanks,
>
> Padma
>
>
>
> > On Feb 24, 2017, at 1:56 PM, Jeena Vinod <HYPERLINK "mailto:
> jeena.vinod@oracle.com"jeena.vinod@oracle.com> wrote:
>
> >
>
> > Thanks for the suggestions.
>
> >
>
> > I did run REFRESH TABLE METADATA command on this path before firing
> select query.
>
> >
>
> > In Drill 1.9, there is an improvement in performance. I have 1.9 setup
> on a 2 node 16GB cluster and here select * with limit 100 is taking less
> time than 1.8, though the number of rows in ParquetGroupScan remains
> unchanged. Select query is taking around 8 minutes and explain plan took
> around 7 minutes. Also in the Web console profile, the query stays in the
> STARTING status for almost 7 minutes.
>
> >
>
> > Query Plan for 1.9:
>
> > 00-00    Screen : rowType = RecordType(ANY *): rowcount = 100.0,
> cumulative cost = {32810.0 rows, 33110.0 cpu, 0.0 io, 0.0 network, 0.0
> memory}, id = 1721
>
> > 00-01      Project(*=[$0]) : rowType = RecordType(ANY *): rowcount =
> 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 network,
> 0.0 memory}, id = 1720
>
> > 00-02        SelectionVectorRemover : rowType = (DrillRecordRow[*]):
> rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0
> network, 0.0 memory}, id = 1719
>
> > 00-03          Limit(fetch=[100]) : rowType = (DrillRecordRow[*]):
> rowcount = 100.0, cumulative cost = {32700.0 rows, 33000.0 cpu, 0.0 io, 0.0
> network, 0.0 memory}, id = 1718
>
> > 00-04            Scan(groupscan=[ParquetGroupScan
> [entries=[ReadEntryWithPath [path=/testdata/part-r-00000-
> 097f7399-7bfb-4e93-b883-3348655fc658.parquet]], selectionRoot=/testdata,
> numFiles=1, usedMetadataFile=true, cacheFileRoot=/testdata,
> columns=[`*`]]]) : rowType = (DrillRecordRow[*]): rowcount = 32600.0,
> cumulative cost = {32600.0 rows, 32600.0 cpu, 0.0 io, 0.0 network, 0.0
> memory}, id = 1717
>
> >
>
> > And from the query profile, it looks like the most time is spent in
> PARQUET_ROW_GROUP_SCAN. I can attach the full JSON profile if it helps.
>
> >
>
> > Can there be further improvement in performance with 1.9?
>
> >
>
> > Regards
>
> > Jeena
>
> >
>
> >
>
> > -----Original Message-----
>
> > From: Padma Penumarthy [mailto:ppenumarthy@mapr.com]
>
> > Sent: Friday, February 24, 2017 11:22 PM
>
> > To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org
>
> > Subject: Re: Explain Plan for Parquet data is taking a lot of timre
>
> >
>
> > Yes, limit is pushed down to parquet reader in 1.9. But, that will not
> help with planning time.
>
> > It is definitely worth trying with 1.9 though.
>
> >
>
> > Thanks,
>
> > Padma
>
> >
>
> >
>
> >> On Feb 24, 2017, at 7:26 AM, Andries Engelbrecht <HYPERLINK "mailto:
> aengelbrecht@mapr.com"aengelbrecht@mapr.com> wrote:
>
> >>
>
> >> Looks like the metadata cache is being used  "usedMetadataFile=true, ".
> But to be sure did you perform a REFRESH TABLE METADATA <path to table> on
> the parquet data?
>
> >>
>
> >>
>
> >> However it looks like it is reading a full batch " rowcount = 32600.0,
> cumulative cost = {32600.0 rows, 32600.0"
>
> >>
>
> >>
>
> >> Didn't the limit operator get pushed down to the parquet reader in 1.9?
>
> >>
>
> >> Perhaps try 1.9 and see if in the ParquetGroupScan the number of rows
> gets reduced to 100.
>
> >>
>
> >>
>
> >> Can you look in the query profile where time is spend, also how long it
> takes before the query starts to run in the WebUI profile.
>
> >>
>
> >>
>
> >> Best Regards
>
> >>
>
> >>
>
> >> Andries Engelbrecht
>
> >>
>
> >>
>
> >> Senior Solutions Architect
>
> >>
>
> >> MapR Alliances and Channels Engineering
>
> >>
>
> >>
>
> >> HYPERLINK "mailto:aengelbrecht@mapr.com"aengelbrecht@mapr.com
>
> >>
>
> >>
>
> >> [1483990071965_mapr-logo-signature.png]
>
> >>
>
> >> ________________________________
>
> >> From: Jinfeng Ni <HYPERLINK "mailto:jni@apache.org"jni@apache.org>
>
> >> Sent: Thursday, February 23, 2017 4:53:34 PM
>
> >> To: user
>
> >> Subject: Re: Explain Plan for Parquet data is taking a lot of timre
>
> >>
>
> >> The reason the plan shows only one single parquet file is because
>
> >> "LIMIT 100" is applied and filter out the rest of them.
>
> >>
>
> >> Agreed that parquet metadata caching might help reduce planning time,
>
> >> when there are large number of parquet files.
>
> >>
>
> >> On Thu, Feb 23, 2017 at 4:44 PM, rahul challapalli
>
> >> <HYPERLINK "mailto:challapallirahul@gmail.com"challapallirahul@
> gmail.com> wrote:
>
> >>> You said there are 2144 parquet files but the plan suggests that you
>
> >>> only have a single parquet file. In any case its a long time to plan
> the query.
>
> >>> Did you try the metadata caching feature [1]?
>
> >>>
>
> >>> Also how many rowgroups and columns are present in the parquet file?
>
> >>>
>
> >>> [1]
>
> >>> https://drill.apache.org/docs/optimizing-parquet-metadata-reading/
>
> >>>
>
> >>> - Rahul
>
> >>>
>
> >>> On Thu, Feb 23, 2017 at 4:24 PM, Jeena Vinod <HYPERLINK "mailto:
> jeena.vinod@oracle.com"jeena.vinod@oracle.com> wrote:
>
> >>>
>
> >>>> Hi,
>
> >>>>
>
> >>>>
>
> >>>>
>
> >>>> Drill is taking 23 minutes for a simple select * query with limit
>
> >>>> 100 on 1GB uncompressed parquet data. EXPLAIN PLAN for this query
>
> >>>> is also taking that long(~23 minutes).
>
> >>>>
>
> >>>> Query: select * from <plugin>.root.`testdata` limit 100;
>
> >>>>
>
> >>>> Query  Plan:
>
> >>>>
>
> >>>> 00-00    Screen : rowType = RecordType(ANY *): rowcount = 100.0,
>
> >>>> cumulative cost = {32810.0 rows, 33110.0 cpu, 0.0 io, 0.0 network,
>
> >>>> 0.0 memory}, id = 1429
>
> >>>>
>
> >>>> 00-01      Project(*=[$0]) : rowType = RecordType(ANY *): rowcount =
>
> >>>> 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0
>
> >>>> network,
>
> >>>> 0.0 memory}, id = 1428
>
> >>>>
>
> >>>> 00-02        SelectionVectorRemover : rowType = (DrillRecordRow[*]):
>
> >>>> rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0
>
> >>>> io, 0.0 network, 0.0 memory}, id = 1427
>
> >>>>
>
> >>>> 00-03          Limit(fetch=[100]) : rowType = (DrillRecordRow[*]):
>
> >>>> rowcount = 100.0, cumulative cost = {32700.0 rows, 33000.0 cpu, 0.0
>
> >>>> io, 0.0 network, 0.0 memory}, id = 1426
>
> >>>>
>
> >>>> 00-04            Scan(groupscan=[ParquetGroupScan
>
> >>>> [entries=[ReadEntryWithPath [path=/testdata/part-r-00000-
>
> >>>> 097f7399-7bfb-4e93-b883-3348655fc658.parquet]],
>
> >>>> selectionRoot=/testdata, numFiles=1, usedMetadataFile=true,
>
> >>>> cacheFileRoot=/testdata,
>
> >>>> columns=[`*`]]]) : rowType = (DrillRecordRow[*]): rowcount =
>
> >>>> 32600.0, cumulative cost = {32600.0 rows, 32600.0 cpu, 0.0 io, 0.0
>
> >>>> network, 0.0 memory}, id = 1425
>
> >>>>
>
> >>>>
>
> >>>>
>
> >>>> I am using Drill1.8 and it is setup on 5 node 32GB cluster and the
>
> >>>> data is in Oracle Storage Cloud Service. When I run the same query
>
> >>>> on 1GB TSV file in this location it is taking only 38 seconds .
>
> >>>>
>
> >>>> Also testdata contains around 2144 .parquet files each around 500KB.
>
> >>>>
>
> >>>>
>
> >>>>
>
> >>>> Is there any additional configuration required for parquet?
>
> >>>>
>
> >>>> Kindly suggest how to improve the response time here.
>
> >>>>
>
> >>>>
>
> >>>>
>
> >>>> Regards
>
> >>>> Jeena
>
> >>>>
>
> >>>>
>
> >>>>
>
> >>>>
>
> >>>>
>
> >>>>
>
> >>>>
>
> >>>>
>
> >>>>
>
> >>>>
>
> >>>>
>
> >
>
>
>
>
>

RE: Explain Plan for Parquet data is taking a lot of timre

Posted by Chetan Kothari <ch...@oracle.com>.
Hi All

 

Any inputs on this?

 

Why creating metadata files recursively should took 1457445 ms when refresh metadata on this path is already done?

 

Regards

Chetan

 

              - -----Original Message-----
From: Jeena Vinod 
Sent: Sunday, March 5, 2017 10:44 PM
To: user@drill.apache.org
Subject: RE: Explain Plan for Parquet data is taking a lot of timre

 

Re- attaching the log file as zip file.

 

Regards

Jeena

 

-----Original Message-----

From: Jeena Vinod

Sent: Sunday, March 05, 2017 9:23 PM

To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org

Subject: RE: Explain Plan for Parquet data is taking a lot of timre

 

Hi Kunal, 

 

Thanks for the response. 

Attaching the log with DEBUG enabled for the mentioned loggers. I had to trim the log for the query, since this mailer allows max 1MB.

 

From the log files, the below step seems to be taking the most time. Since refresh metadata on this path is already done, I am unsure what this means.

      -Creating metadata files recursively took 1457445 ms

 

Also I have 4 core nodes and the planner.width.max_per_node value is currently 3.

I tried with values 6 and 8, but did not see significant improvement in response time. How do we get the optimal value for this property on a cluster?

 

Regards

Jeena

 

-----Original Message-----

From: Kunal Khatua [mailto:kkhatua@mapr.com]

Sent: Thursday, March 02, 2017 7:25 AM

To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org

Subject: Re: Explain Plan for Parquet data is taking a lot of timre

 

Hi Jeena

 

 

The JSON profile does not reveal much about why the planning time took so long, but only give you information from the physical plan and when the planning approximately completed (7+min for 2node; 15+min for 5node).

 

Drillbit logs, however, will give you more information. For this, you'll need to look in the log for with information like

 

 

2017-02-23 14:00:54,609 [27513143-8718-7a47-a2d4-06850755568a:foreman] DEBUG o.a.d.e.p.s.h.DefaultSqlHandler - VOLCANO:Physical Planning (49588ms):

 

You might need to enable your logback.xml to pop out this information (by enabling DEBUG level logging for these classes).

These are the recommended loggers you can enable DEBUG for:

org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler

org.apache.drill.exec.work.foreman.Foreman

 

 

You can share the drillbit log file with these as a run thereafter.

 

 

Also, Your profile JSONs indicate that you have a fairly slow underlying filesystem.

 

 

I'm seeing an average of

 

3m45s to read 945K rows (2 node setup)

 

and

 

2m25s to read 1.5M rows (5node setup)

 

 

Your 2node setup shows 6 fragments processing 29 batches; while 5node setup shows 15 fragments processing 46 batches. For the number of rows, the amount of time spent is very high, which makes me believe that your filesystem (Oracle Cloud Storage service) is itself quite slow.

 

For speeding up execution, you can try changing the planner.width.max_per_node to a higher value (like the number of cores on the node). This should increase parallelization and the utilization of all the cores by Drill.

 

 

Kunal Khatua

 

Engineering

 

[MapR]<http://www.mapr.com/>

 

HYPERLINK "http://www.mapr.com%3chttp:/www.mapr.com/"www.mapr.com<http://www.mapr.com/>

 

________________________________

From: Jeena Vinod <HYPERLINK "mailto:jeena.vinod@oracle.com"jeena.vinod@oracle.com>

Sent: Tuesday, February 28, 2017 12:24:52 PM

To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org

Subject: RE: Explain Plan for Parquet data is taking a lot of timre

 

Kindly let know if there are any pointers on how to improve response time for parquet data here.

 

Regards

Jeena

 

-----Original Message-----

From: Jeena Vinod

Sent: Tuesday, February 28, 2017 4:25 AM

To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org

Subject: RE: Explain Plan for Parquet data is taking a lot of timre

 

Hi,

 

I have 2 Drill 1.9 installations. One is a 5 node 32GB cluster and other is a 2 node 16GB cluster. And I am running the same query in both the places.

select * from `testdata` where <condition> limit 100; testdata is 1GB uncompressed parquet data.

 

The query response time is found as below:

2 node cluster - 13min

5 node cluster - 19min

 

I was expecting 5 node cluster to be faster, but the results say otherwise.

In the query profile, as expected, 5 node cluster has more minor fragments, but still the scan time is higher. Attached the json profile for both.

Is this in anyway related to the max batches/max records for row group scan?

 

Any suggestions on how we can get better response time in the 5 node cluster is appreciated.

 

Regards

Jeena

 

-----Original Message-----

From: Jeena Vinod

Sent: Sunday, February 26, 2017 2:22 AM

To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org

Subject: RE: Explain Plan for Parquet data is taking a lot of timre

 

Please find attached the full JSON profile.

 

Regards

Jeena

 

-----Original Message-----

From: Padma Penumarthy [mailto:ppenumarthy@mapr.com]

Sent: Saturday, February 25, 2017 3:31 AM

To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org

Subject: Re: Explain Plan for Parquet data is taking a lot of timre

 

Yes, please do send the JSON profile.

 

Thanks,

Padma

 

> On Feb 24, 2017, at 1:56 PM, Jeena Vinod <HYPERLINK "mailto:jeena.vinod@oracle.com"jeena.vinod@oracle.com> wrote:

> 

> Thanks for the suggestions.

> 

> I did run REFRESH TABLE METADATA command on this path before firing select query.

> 

> In Drill 1.9, there is an improvement in performance. I have 1.9 setup on a 2 node 16GB cluster and here select * with limit 100 is taking less time than 1.8, though the number of rows in ParquetGroupScan remains unchanged. Select query is taking around 8 minutes and explain plan took around 7 minutes. Also in the Web console profile, the query stays in the STARTING status for almost 7 minutes.

> 

> Query Plan for 1.9:

> 00-00    Screen : rowType = RecordType(ANY *): rowcount = 100.0, cumulative cost = {32810.0 rows, 33110.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1721

> 00-01      Project(*=[$0]) : rowType = RecordType(ANY *): rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1720

> 00-02        SelectionVectorRemover : rowType = (DrillRecordRow[*]): rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1719

> 00-03          Limit(fetch=[100]) : rowType = (DrillRecordRow[*]): rowcount = 100.0, cumulative cost = {32700.0 rows, 33000.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1718

> 00-04            Scan(groupscan=[ParquetGroupScan [entries=[ReadEntryWithPath [path=/testdata/part-r-00000-097f7399-7bfb-4e93-b883-3348655fc658.parquet]], selectionRoot=/testdata, numFiles=1, usedMetadataFile=true, cacheFileRoot=/testdata, columns=[`*`]]]) : rowType = (DrillRecordRow[*]): rowcount = 32600.0, cumulative cost = {32600.0 rows, 32600.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1717

> 

> And from the query profile, it looks like the most time is spent in PARQUET_ROW_GROUP_SCAN. I can attach the full JSON profile if it helps.

> 

> Can there be further improvement in performance with 1.9?

> 

> Regards

> Jeena

> 

> 

> -----Original Message-----

> From: Padma Penumarthy [mailto:ppenumarthy@mapr.com]

> Sent: Friday, February 24, 2017 11:22 PM

> To: HYPERLINK "mailto:user@drill.apache.org"user@drill.apache.org

> Subject: Re: Explain Plan for Parquet data is taking a lot of timre

> 

> Yes, limit is pushed down to parquet reader in 1.9. But, that will not help with planning time.

> It is definitely worth trying with 1.9 though.

> 

> Thanks,

> Padma

> 

> 

>> On Feb 24, 2017, at 7:26 AM, Andries Engelbrecht <HYPERLINK "mailto:aengelbrecht@mapr.com"aengelbrecht@mapr.com> wrote:

>> 

>> Looks like the metadata cache is being used  "usedMetadataFile=true, ". But to be sure did you perform a REFRESH TABLE METADATA <path to table> on the parquet data?

>> 

>> 

>> However it looks like it is reading a full batch " rowcount = 32600.0, cumulative cost = {32600.0 rows, 32600.0"

>> 

>> 

>> Didn't the limit operator get pushed down to the parquet reader in 1.9?

>> 

>> Perhaps try 1.9 and see if in the ParquetGroupScan the number of rows gets reduced to 100.

>> 

>> 

>> Can you look in the query profile where time is spend, also how long it takes before the query starts to run in the WebUI profile.

>> 

>> 

>> Best Regards

>> 

>> 

>> Andries Engelbrecht

>> 

>> 

>> Senior Solutions Architect

>> 

>> MapR Alliances and Channels Engineering

>> 

>> 

>> HYPERLINK "mailto:aengelbrecht@mapr.com"aengelbrecht@mapr.com

>> 

>> 

>> [1483990071965_mapr-logo-signature.png]

>> 

>> ________________________________

>> From: Jinfeng Ni <HYPERLINK "mailto:jni@apache.org"jni@apache.org>

>> Sent: Thursday, February 23, 2017 4:53:34 PM

>> To: user

>> Subject: Re: Explain Plan for Parquet data is taking a lot of timre

>> 

>> The reason the plan shows only one single parquet file is because 

>> "LIMIT 100" is applied and filter out the rest of them.

>> 

>> Agreed that parquet metadata caching might help reduce planning time, 

>> when there are large number of parquet files.

>> 

>> On Thu, Feb 23, 2017 at 4:44 PM, rahul challapalli 

>> <HYPERLINK "mailto:challapallirahul@gmail.com"challapallirahul@gmail.com> wrote:

>>> You said there are 2144 parquet files but the plan suggests that you 

>>> only have a single parquet file. In any case its a long time to plan the query.

>>> Did you try the metadata caching feature [1]?

>>> 

>>> Also how many rowgroups and columns are present in the parquet file?

>>> 

>>> [1]

>>> https://drill.apache.org/docs/optimizing-parquet-metadata-reading/

>>> 

>>> - Rahul

>>> 

>>> On Thu, Feb 23, 2017 at 4:24 PM, Jeena Vinod <HYPERLINK "mailto:jeena.vinod@oracle.com"jeena.vinod@oracle.com> wrote:

>>> 

>>>> Hi,

>>>> 

>>>> 

>>>> 

>>>> Drill is taking 23 minutes for a simple select * query with limit

>>>> 100 on 1GB uncompressed parquet data. EXPLAIN PLAN for this query 

>>>> is also taking that long(~23 minutes).

>>>> 

>>>> Query: select * from <plugin>.root.`testdata` limit 100;

>>>> 

>>>> Query  Plan:

>>>> 

>>>> 00-00    Screen : rowType = RecordType(ANY *): rowcount = 100.0,

>>>> cumulative cost = {32810.0 rows, 33110.0 cpu, 0.0 io, 0.0 network,

>>>> 0.0 memory}, id = 1429

>>>> 

>>>> 00-01      Project(*=[$0]) : rowType = RecordType(ANY *): rowcount =

>>>> 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 

>>>> network,

>>>> 0.0 memory}, id = 1428

>>>> 

>>>> 00-02        SelectionVectorRemover : rowType = (DrillRecordRow[*]):

>>>> rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 

>>>> io, 0.0 network, 0.0 memory}, id = 1427

>>>> 

>>>> 00-03          Limit(fetch=[100]) : rowType = (DrillRecordRow[*]):

>>>> rowcount = 100.0, cumulative cost = {32700.0 rows, 33000.0 cpu, 0.0 

>>>> io, 0.0 network, 0.0 memory}, id = 1426

>>>> 

>>>> 00-04            Scan(groupscan=[ParquetGroupScan

>>>> [entries=[ReadEntryWithPath [path=/testdata/part-r-00000- 

>>>> 097f7399-7bfb-4e93-b883-3348655fc658.parquet]],

>>>> selectionRoot=/testdata, numFiles=1, usedMetadataFile=true, 

>>>> cacheFileRoot=/testdata,

>>>> columns=[`*`]]]) : rowType = (DrillRecordRow[*]): rowcount = 

>>>> 32600.0, cumulative cost = {32600.0 rows, 32600.0 cpu, 0.0 io, 0.0 

>>>> network, 0.0 memory}, id = 1425

>>>> 

>>>> 

>>>> 

>>>> I am using Drill1.8 and it is setup on 5 node 32GB cluster and the 

>>>> data is in Oracle Storage Cloud Service. When I run the same query 

>>>> on 1GB TSV file in this location it is taking only 38 seconds .

>>>> 

>>>> Also testdata contains around 2144 .parquet files each around 500KB.

>>>> 

>>>> 

>>>> 

>>>> Is there any additional configuration required for parquet?

>>>> 

>>>> Kindly suggest how to improve the response time here.

>>>> 

>>>> 

>>>> 

>>>> Regards

>>>> Jeena

>>>> 

>>>> 

>>>> 

>>>> 

>>>> 

>>>> 

>>>> 

>>>> 

>>>> 

>>>> 

>>>> 

> 

 

 

Re: Explain Plan for Parquet data is taking a lot of timre

Posted by Padma Penumarthy <pp...@mapr.com>.
Basically, it is rebuilding the metadata cache (reading all the parquet files that are there), 
since it thinks something is changed in the directory.

During planning, we check if metadata cache file needs to be updated by checking 
modification time of directory against modification time of metadata cache file.  
If directory has more recent modification time, it is considered 
that metadata cache file is stale and will be rebuilt.

2017-03-03 09:10:34,883 [274686d2-07ed-3fa9-a46e-682f4c5dc030:foreman] INFO  o.a.d.exec.store.parquet.Metadata - Directory xxx/testdata was modified. Took 973 ms to check modification time of 1 directories

Do you know if any new data is getting added or something happening in that directory that
could change the modification time of the directory ? 

Thanks,
Padma


> On Mar 5, 2017, at 9:13 AM, Jeena Vinod <je...@oracle.com> wrote:
> 
> Re- attaching the log file as zip file.
> 
> Regards
> Jeena
> 
> -----Original Message-----
> From: Jeena Vinod 
> Sent: Sunday, March 05, 2017 9:23 PM
> To: user@drill.apache.org
> Subject: RE: Explain Plan for Parquet data is taking a lot of timre
> 
> Hi Kunal, 
> 
> Thanks for the response. 
> Attaching the log with DEBUG enabled for the mentioned loggers. I had to trim the log for the query, since this mailer allows max 1MB.
> 
> From the log files, the below step seems to be taking the most time. Since refresh metadata on this path is already done, I am unsure what this means.
> 	-Creating metadata files recursively took 1457445 ms
> 
> Also I have 4 core nodes and the planner.width.max_per_node value is currently 3.
> I tried with values 6 and 8, but did not see significant improvement in response time. How do we get the optimal value for this property on a cluster?
> 
> Regards
> Jeena
> 
> -----Original Message-----
> From: Kunal Khatua [mailto:kkhatua@mapr.com]
> Sent: Thursday, March 02, 2017 7:25 AM
> To: user@drill.apache.org
> Subject: Re: Explain Plan for Parquet data is taking a lot of timre
> 
> Hi Jeena
> 
> 
> The JSON profile does not reveal much about why the planning time took so long, but only give you information from the physical plan and when the planning approximately completed (7+min for 2node; 15+min for 5node).
> 
> Drillbit logs, however, will give you more information. For this, you'll need to look in the log for with information like
> 
> 
> 2017-02-23 14:00:54,609 [27513143-8718-7a47-a2d4-06850755568a:foreman] DEBUG o.a.d.e.p.s.h.DefaultSqlHandler - VOLCANO:Physical Planning (49588ms):
> 
> You might need to enable your logback.xml to pop out this information (by enabling DEBUG level logging for these classes).
> These are the recommended loggers you can enable DEBUG for:
> org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler
> org.apache.drill.exec.work.foreman.Foreman
> 
> 
> You can share the drillbit log file with these as a run thereafter.
> 
> 
> Also, Your profile JSONs indicate that you have a fairly slow underlying filesystem.
> 
> 
> I'm seeing an average of
> 
> 3m45s to read 945K rows (2 node setup)
> 
> and
> 
> 2m25s to read 1.5M rows (5node setup)
> 
> 
> Your 2node setup shows 6 fragments processing 29 batches; while 5node setup shows 15 fragments processing 46 batches. For the number of rows, the amount of time spent is very high, which makes me believe that your filesystem (Oracle Cloud Storage service) is itself quite slow.
> 
> For speeding up execution, you can try changing the planner.width.max_per_node to a higher value (like the number of cores on the node). This should increase parallelization and the utilization of all the cores by Drill.
> 
> 
> Kunal Khatua
> 
> Engineering
> 
> [MapR]<http://www.mapr.com/>
> 
> www.mapr.com<http://www.mapr.com/>
> 
> ________________________________
> From: Jeena Vinod <je...@oracle.com>
> Sent: Tuesday, February 28, 2017 12:24:52 PM
> To: user@drill.apache.org
> Subject: RE: Explain Plan for Parquet data is taking a lot of timre
> 
> Kindly let know if there are any pointers on how to improve response time for parquet data here.
> 
> Regards
> Jeena
> 
> -----Original Message-----
> From: Jeena Vinod
> Sent: Tuesday, February 28, 2017 4:25 AM
> To: user@drill.apache.org
> Subject: RE: Explain Plan for Parquet data is taking a lot of timre
> 
> Hi,
> 
> I have 2 Drill 1.9 installations. One is a 5 node 32GB cluster and other is a 2 node 16GB cluster. And I am running the same query in both the places.
> select * from `testdata` where <condition> limit 100; testdata is 1GB uncompressed parquet data.
> 
> The query response time is found as below:
> 2 node cluster - 13min
> 5 node cluster - 19min
> 
> I was expecting 5 node cluster to be faster, but the results say otherwise.
> In the query profile, as expected, 5 node cluster has more minor fragments, but still the scan time is higher. Attached the json profile for both.
> Is this in anyway related to the max batches/max records for row group scan?
> 
> Any suggestions on how we can get better response time in the 5 node cluster is appreciated.
> 
> Regards
> Jeena
> 
> -----Original Message-----
> From: Jeena Vinod
> Sent: Sunday, February 26, 2017 2:22 AM
> To: user@drill.apache.org
> Subject: RE: Explain Plan for Parquet data is taking a lot of timre
> 
> Please find attached the full JSON profile.
> 
> Regards
> Jeena
> 
> -----Original Message-----
> From: Padma Penumarthy [mailto:ppenumarthy@mapr.com]
> Sent: Saturday, February 25, 2017 3:31 AM
> To: user@drill.apache.org
> Subject: Re: Explain Plan for Parquet data is taking a lot of timre
> 
> Yes, please do send the JSON profile.
> 
> Thanks,
> Padma
> 
>> On Feb 24, 2017, at 1:56 PM, Jeena Vinod <je...@oracle.com> wrote:
>> 
>> Thanks for the suggestions.
>> 
>> I did run REFRESH TABLE METADATA command on this path before firing select query.
>> 
>> In Drill 1.9, there is an improvement in performance. I have 1.9 setup on a 2 node 16GB cluster and here select * with limit 100 is taking less time than 1.8, though the number of rows in ParquetGroupScan remains unchanged. Select query is taking around 8 minutes and explain plan took around 7 minutes. Also in the Web console profile, the query stays in the STARTING status for almost 7 minutes.
>> 
>> Query Plan for 1.9:
>> 00-00    Screen : rowType = RecordType(ANY *): rowcount = 100.0, cumulative cost = {32810.0 rows, 33110.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1721
>> 00-01      Project(*=[$0]) : rowType = RecordType(ANY *): rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1720
>> 00-02        SelectionVectorRemover : rowType = (DrillRecordRow[*]): rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1719
>> 00-03          Limit(fetch=[100]) : rowType = (DrillRecordRow[*]): rowcount = 100.0, cumulative cost = {32700.0 rows, 33000.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1718
>> 00-04            Scan(groupscan=[ParquetGroupScan [entries=[ReadEntryWithPath [path=/testdata/part-r-00000-097f7399-7bfb-4e93-b883-3348655fc658.parquet]], selectionRoot=/testdata, numFiles=1, usedMetadataFile=true, cacheFileRoot=/testdata, columns=[`*`]]]) : rowType = (DrillRecordRow[*]): rowcount = 32600.0, cumulative cost = {32600.0 rows, 32600.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1717
>> 
>> And from the query profile, it looks like the most time is spent in PARQUET_ROW_GROUP_SCAN. I can attach the full JSON profile if it helps.
>> 
>> Can there be further improvement in performance with 1.9?
>> 
>> Regards
>> Jeena
>> 
>> 
>> -----Original Message-----
>> From: Padma Penumarthy [mailto:ppenumarthy@mapr.com]
>> Sent: Friday, February 24, 2017 11:22 PM
>> To: user@drill.apache.org
>> Subject: Re: Explain Plan for Parquet data is taking a lot of timre
>> 
>> Yes, limit is pushed down to parquet reader in 1.9. But, that will not help with planning time.
>> It is definitely worth trying with 1.9 though.
>> 
>> Thanks,
>> Padma
>> 
>> 
>>> On Feb 24, 2017, at 7:26 AM, Andries Engelbrecht <ae...@mapr.com> wrote:
>>> 
>>> Looks like the metadata cache is being used  "usedMetadataFile=true, ". But to be sure did you perform a REFRESH TABLE METADATA <path to table> on the parquet data?
>>> 
>>> 
>>> However it looks like it is reading a full batch " rowcount = 32600.0, cumulative cost = {32600.0 rows, 32600.0"
>>> 
>>> 
>>> Didn't the limit operator get pushed down to the parquet reader in 1.9?
>>> 
>>> Perhaps try 1.9 and see if in the ParquetGroupScan the number of rows gets reduced to 100.
>>> 
>>> 
>>> Can you look in the query profile where time is spend, also how long it takes before the query starts to run in the WebUI profile.
>>> 
>>> 
>>> Best Regards
>>> 
>>> 
>>> Andries Engelbrecht
>>> 
>>> 
>>> Senior Solutions Architect
>>> 
>>> MapR Alliances and Channels Engineering
>>> 
>>> 
>>> aengelbrecht@mapr.com
>>> 
>>> 
>>> [1483990071965_mapr-logo-signature.png]
>>> 
>>> ________________________________
>>> From: Jinfeng Ni <jn...@apache.org>
>>> Sent: Thursday, February 23, 2017 4:53:34 PM
>>> To: user
>>> Subject: Re: Explain Plan for Parquet data is taking a lot of timre
>>> 
>>> The reason the plan shows only one single parquet file is because 
>>> "LIMIT 100" is applied and filter out the rest of them.
>>> 
>>> Agreed that parquet metadata caching might help reduce planning time, 
>>> when there are large number of parquet files.
>>> 
>>> On Thu, Feb 23, 2017 at 4:44 PM, rahul challapalli 
>>> <ch...@gmail.com> wrote:
>>>> You said there are 2144 parquet files but the plan suggests that you 
>>>> only have a single parquet file. In any case its a long time to plan the query.
>>>> Did you try the metadata caching feature [1]?
>>>> 
>>>> Also how many rowgroups and columns are present in the parquet file?
>>>> 
>>>> [1]
>>>> https://drill.apache.org/docs/optimizing-parquet-metadata-reading/
>>>> 
>>>> - Rahul
>>>> 
>>>> On Thu, Feb 23, 2017 at 4:24 PM, Jeena Vinod <je...@oracle.com> wrote:
>>>> 
>>>>> Hi,
>>>>> 
>>>>> 
>>>>> 
>>>>> Drill is taking 23 minutes for a simple select * query with limit
>>>>> 100 on 1GB uncompressed parquet data. EXPLAIN PLAN for this query 
>>>>> is also taking that long(~23 minutes).
>>>>> 
>>>>> Query: select * from <plugin>.root.`testdata` limit 100;
>>>>> 
>>>>> Query  Plan:
>>>>> 
>>>>> 00-00    Screen : rowType = RecordType(ANY *): rowcount = 100.0,
>>>>> cumulative cost = {32810.0 rows, 33110.0 cpu, 0.0 io, 0.0 network,
>>>>> 0.0 memory}, id = 1429
>>>>> 
>>>>> 00-01      Project(*=[$0]) : rowType = RecordType(ANY *): rowcount =
>>>>> 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 
>>>>> network,
>>>>> 0.0 memory}, id = 1428
>>>>> 
>>>>> 00-02        SelectionVectorRemover : rowType = (DrillRecordRow[*]):
>>>>> rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 
>>>>> io, 0.0 network, 0.0 memory}, id = 1427
>>>>> 
>>>>> 00-03          Limit(fetch=[100]) : rowType = (DrillRecordRow[*]):
>>>>> rowcount = 100.0, cumulative cost = {32700.0 rows, 33000.0 cpu, 0.0 
>>>>> io, 0.0 network, 0.0 memory}, id = 1426
>>>>> 
>>>>> 00-04            Scan(groupscan=[ParquetGroupScan
>>>>> [entries=[ReadEntryWithPath [path=/testdata/part-r-00000- 
>>>>> 097f7399-7bfb-4e93-b883-3348655fc658.parquet]],
>>>>> selectionRoot=/testdata, numFiles=1, usedMetadataFile=true, 
>>>>> cacheFileRoot=/testdata,
>>>>> columns=[`*`]]]) : rowType = (DrillRecordRow[*]): rowcount = 
>>>>> 32600.0, cumulative cost = {32600.0 rows, 32600.0 cpu, 0.0 io, 0.0 
>>>>> network, 0.0 memory}, id = 1425
>>>>> 
>>>>> 
>>>>> 
>>>>> I am using Drill1.8 and it is setup on 5 node 32GB cluster and the 
>>>>> data is in Oracle Storage Cloud Service. When I run the same query 
>>>>> on 1GB TSV file in this location it is taking only 38 seconds .
>>>>> 
>>>>> Also testdata contains around 2144 .parquet files each around 500KB.
>>>>> 
>>>>> 
>>>>> 
>>>>> Is there any additional configuration required for parquet?
>>>>> 
>>>>> Kindly suggest how to improve the response time here.
>>>>> 
>>>>> 
>>>>> 
>>>>> Regards
>>>>> Jeena
>>>>> 
>>>>> 
>>>>> 
>>>>> 
>>>>> 
>>>>> 
>>>>> 
>>>>> 
>>>>> 
>>>>> 
>>>>> 
>> 
> 
> <drillbit.zip>


RE: Explain Plan for Parquet data is taking a lot of timre

Posted by Jeena Vinod <je...@oracle.com>.
Re- attaching the log file as zip file.

Regards
Jeena

-----Original Message-----
From: Jeena Vinod 
Sent: Sunday, March 05, 2017 9:23 PM
To: user@drill.apache.org
Subject: RE: Explain Plan for Parquet data is taking a lot of timre

Hi Kunal, 

Thanks for the response. 
Attaching the log with DEBUG enabled for the mentioned loggers. I had to trim the log for the query, since this mailer allows max 1MB.

From the log files, the below step seems to be taking the most time. Since refresh metadata on this path is already done, I am unsure what this means.
	-Creating metadata files recursively took 1457445 ms

Also I have 4 core nodes and the planner.width.max_per_node value is currently 3.
I tried with values 6 and 8, but did not see significant improvement in response time. How do we get the optimal value for this property on a cluster?

Regards
Jeena

-----Original Message-----
From: Kunal Khatua [mailto:kkhatua@mapr.com]
Sent: Thursday, March 02, 2017 7:25 AM
To: user@drill.apache.org
Subject: Re: Explain Plan for Parquet data is taking a lot of timre

Hi Jeena


The JSON profile does not reveal much about why the planning time took so long, but only give you information from the physical plan and when the planning approximately completed (7+min for 2node; 15+min for 5node).

Drillbit logs, however, will give you more information. For this, you'll need to look in the log for with information like


2017-02-23 14:00:54,609 [27513143-8718-7a47-a2d4-06850755568a:foreman] DEBUG o.a.d.e.p.s.h.DefaultSqlHandler - VOLCANO:Physical Planning (49588ms):

You might need to enable your logback.xml to pop out this information (by enabling DEBUG level logging for these classes).
These are the recommended loggers you can enable DEBUG for:
org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler
org.apache.drill.exec.work.foreman.Foreman


You can share the drillbit log file with these as a run thereafter.


Also, Your profile JSONs indicate that you have a fairly slow underlying filesystem.


I'm seeing an average of

3m45s to read 945K rows (2 node setup)

and

2m25s to read 1.5M rows (5node setup)


Your 2node setup shows 6 fragments processing 29 batches; while 5node setup shows 15 fragments processing 46 batches. For the number of rows, the amount of time spent is very high, which makes me believe that your filesystem (Oracle Cloud Storage service) is itself quite slow.

For speeding up execution, you can try changing the planner.width.max_per_node to a higher value (like the number of cores on the node). This should increase parallelization and the utilization of all the cores by Drill.


Kunal Khatua

Engineering

[MapR]<http://www.mapr.com/>

www.mapr.com<http://www.mapr.com/>

________________________________
From: Jeena Vinod <je...@oracle.com>
Sent: Tuesday, February 28, 2017 12:24:52 PM
To: user@drill.apache.org
Subject: RE: Explain Plan for Parquet data is taking a lot of timre

Kindly let know if there are any pointers on how to improve response time for parquet data here.

Regards
Jeena

-----Original Message-----
From: Jeena Vinod
Sent: Tuesday, February 28, 2017 4:25 AM
To: user@drill.apache.org
Subject: RE: Explain Plan for Parquet data is taking a lot of timre

Hi,

I have 2 Drill 1.9 installations. One is a 5 node 32GB cluster and other is a 2 node 16GB cluster. And I am running the same query in both the places.
select * from `testdata` where <condition> limit 100; testdata is 1GB uncompressed parquet data.

The query response time is found as below:
2 node cluster - 13min
5 node cluster - 19min

I was expecting 5 node cluster to be faster, but the results say otherwise.
In the query profile, as expected, 5 node cluster has more minor fragments, but still the scan time is higher. Attached the json profile for both.
Is this in anyway related to the max batches/max records for row group scan?

Any suggestions on how we can get better response time in the 5 node cluster is appreciated.

Regards
Jeena

-----Original Message-----
From: Jeena Vinod
Sent: Sunday, February 26, 2017 2:22 AM
To: user@drill.apache.org
Subject: RE: Explain Plan for Parquet data is taking a lot of timre

Please find attached the full JSON profile.

Regards
Jeena

-----Original Message-----
From: Padma Penumarthy [mailto:ppenumarthy@mapr.com]
Sent: Saturday, February 25, 2017 3:31 AM
To: user@drill.apache.org
Subject: Re: Explain Plan for Parquet data is taking a lot of timre

Yes, please do send the JSON profile.

Thanks,
Padma

> On Feb 24, 2017, at 1:56 PM, Jeena Vinod <je...@oracle.com> wrote:
>
> Thanks for the suggestions.
>
> I did run REFRESH TABLE METADATA command on this path before firing select query.
>
> In Drill 1.9, there is an improvement in performance. I have 1.9 setup on a 2 node 16GB cluster and here select * with limit 100 is taking less time than 1.8, though the number of rows in ParquetGroupScan remains unchanged. Select query is taking around 8 minutes and explain plan took around 7 minutes. Also in the Web console profile, the query stays in the STARTING status for almost 7 minutes.
>
> Query Plan for 1.9:
> 00-00    Screen : rowType = RecordType(ANY *): rowcount = 100.0, cumulative cost = {32810.0 rows, 33110.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1721
> 00-01      Project(*=[$0]) : rowType = RecordType(ANY *): rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1720
> 00-02        SelectionVectorRemover : rowType = (DrillRecordRow[*]): rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1719
> 00-03          Limit(fetch=[100]) : rowType = (DrillRecordRow[*]): rowcount = 100.0, cumulative cost = {32700.0 rows, 33000.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1718
> 00-04            Scan(groupscan=[ParquetGroupScan [entries=[ReadEntryWithPath [path=/testdata/part-r-00000-097f7399-7bfb-4e93-b883-3348655fc658.parquet]], selectionRoot=/testdata, numFiles=1, usedMetadataFile=true, cacheFileRoot=/testdata, columns=[`*`]]]) : rowType = (DrillRecordRow[*]): rowcount = 32600.0, cumulative cost = {32600.0 rows, 32600.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1717
>
> And from the query profile, it looks like the most time is spent in PARQUET_ROW_GROUP_SCAN. I can attach the full JSON profile if it helps.
>
> Can there be further improvement in performance with 1.9?
>
> Regards
> Jeena
>
>
> -----Original Message-----
> From: Padma Penumarthy [mailto:ppenumarthy@mapr.com]
> Sent: Friday, February 24, 2017 11:22 PM
> To: user@drill.apache.org
> Subject: Re: Explain Plan for Parquet data is taking a lot of timre
>
> Yes, limit is pushed down to parquet reader in 1.9. But, that will not help with planning time.
> It is definitely worth trying with 1.9 though.
>
> Thanks,
> Padma
>
>
>> On Feb 24, 2017, at 7:26 AM, Andries Engelbrecht <ae...@mapr.com> wrote:
>>
>> Looks like the metadata cache is being used  "usedMetadataFile=true, ". But to be sure did you perform a REFRESH TABLE METADATA <path to table> on the parquet data?
>>
>>
>> However it looks like it is reading a full batch " rowcount = 32600.0, cumulative cost = {32600.0 rows, 32600.0"
>>
>>
>> Didn't the limit operator get pushed down to the parquet reader in 1.9?
>>
>> Perhaps try 1.9 and see if in the ParquetGroupScan the number of rows gets reduced to 100.
>>
>>
>> Can you look in the query profile where time is spend, also how long it takes before the query starts to run in the WebUI profile.
>>
>>
>> Best Regards
>>
>>
>> Andries Engelbrecht
>>
>>
>> Senior Solutions Architect
>>
>> MapR Alliances and Channels Engineering
>>
>>
>> aengelbrecht@mapr.com
>>
>>
>> [1483990071965_mapr-logo-signature.png]
>>
>> ________________________________
>> From: Jinfeng Ni <jn...@apache.org>
>> Sent: Thursday, February 23, 2017 4:53:34 PM
>> To: user
>> Subject: Re: Explain Plan for Parquet data is taking a lot of timre
>>
>> The reason the plan shows only one single parquet file is because 
>> "LIMIT 100" is applied and filter out the rest of them.
>>
>> Agreed that parquet metadata caching might help reduce planning time, 
>> when there are large number of parquet files.
>>
>> On Thu, Feb 23, 2017 at 4:44 PM, rahul challapalli 
>> <ch...@gmail.com> wrote:
>>> You said there are 2144 parquet files but the plan suggests that you 
>>> only have a single parquet file. In any case its a long time to plan the query.
>>> Did you try the metadata caching feature [1]?
>>>
>>> Also how many rowgroups and columns are present in the parquet file?
>>>
>>> [1]
>>> https://drill.apache.org/docs/optimizing-parquet-metadata-reading/
>>>
>>> - Rahul
>>>
>>> On Thu, Feb 23, 2017 at 4:24 PM, Jeena Vinod <je...@oracle.com> wrote:
>>>
>>>> Hi,
>>>>
>>>>
>>>>
>>>> Drill is taking 23 minutes for a simple select * query with limit
>>>> 100 on 1GB uncompressed parquet data. EXPLAIN PLAN for this query 
>>>> is also taking that long(~23 minutes).
>>>>
>>>> Query: select * from <plugin>.root.`testdata` limit 100;
>>>>
>>>> Query  Plan:
>>>>
>>>> 00-00    Screen : rowType = RecordType(ANY *): rowcount = 100.0,
>>>> cumulative cost = {32810.0 rows, 33110.0 cpu, 0.0 io, 0.0 network,
>>>> 0.0 memory}, id = 1429
>>>>
>>>> 00-01      Project(*=[$0]) : rowType = RecordType(ANY *): rowcount =
>>>> 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 
>>>> network,
>>>> 0.0 memory}, id = 1428
>>>>
>>>> 00-02        SelectionVectorRemover : rowType = (DrillRecordRow[*]):
>>>> rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 
>>>> io, 0.0 network, 0.0 memory}, id = 1427
>>>>
>>>> 00-03          Limit(fetch=[100]) : rowType = (DrillRecordRow[*]):
>>>> rowcount = 100.0, cumulative cost = {32700.0 rows, 33000.0 cpu, 0.0 
>>>> io, 0.0 network, 0.0 memory}, id = 1426
>>>>
>>>> 00-04            Scan(groupscan=[ParquetGroupScan
>>>> [entries=[ReadEntryWithPath [path=/testdata/part-r-00000- 
>>>> 097f7399-7bfb-4e93-b883-3348655fc658.parquet]],
>>>> selectionRoot=/testdata, numFiles=1, usedMetadataFile=true, 
>>>> cacheFileRoot=/testdata,
>>>> columns=[`*`]]]) : rowType = (DrillRecordRow[*]): rowcount = 
>>>> 32600.0, cumulative cost = {32600.0 rows, 32600.0 cpu, 0.0 io, 0.0 
>>>> network, 0.0 memory}, id = 1425
>>>>
>>>>
>>>>
>>>> I am using Drill1.8 and it is setup on 5 node 32GB cluster and the 
>>>> data is in Oracle Storage Cloud Service. When I run the same query 
>>>> on 1GB TSV file in this location it is taking only 38 seconds .
>>>>
>>>> Also testdata contains around 2144 .parquet files each around 500KB.
>>>>
>>>>
>>>>
>>>> Is there any additional configuration required for parquet?
>>>>
>>>> Kindly suggest how to improve the response time here.
>>>>
>>>>
>>>>
>>>> Regards
>>>> Jeena
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>


RE: Explain Plan for Parquet data is taking a lot of timre

Posted by Jeena Vinod <je...@oracle.com>.
Hi Kunal, 

Thanks for the response. 
Attaching the log with DEBUG enabled for the mentioned loggers. I had to trim the log for the query, since this mailer allows max 1MB.

From the log files, the below step seems to be taking the most time. Since refresh metadata on this path is already done, I am unsure what this means.
	-Creating metadata files recursively took 1457445 ms

Also I have 4 core nodes and the planner.width.max_per_node value is currently 3.
I tried with values 6 and 8, but did not see significant improvement in response time. How do we get the optimal value for this property on a cluster?

Regards
Jeena

-----Original Message-----
From: Kunal Khatua [mailto:kkhatua@mapr.com]
Sent: Thursday, March 02, 2017 7:25 AM
To: user@drill.apache.org
Subject: Re: Explain Plan for Parquet data is taking a lot of timre

Hi Jeena


The JSON profile does not reveal much about why the planning time took so long, but only give you information from the physical plan and when the planning approximately completed (7+min for 2node; 15+min for 5node).

Drillbit logs, however, will give you more information. For this, you'll need to look in the log for with information like


2017-02-23 14:00:54,609 [27513143-8718-7a47-a2d4-06850755568a:foreman] DEBUG o.a.d.e.p.s.h.DefaultSqlHandler - VOLCANO:Physical Planning (49588ms):

You might need to enable your logback.xml to pop out this information (by enabling DEBUG level logging for these classes).
These are the recommended loggers you can enable DEBUG for:
org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler
org.apache.drill.exec.work.foreman.Foreman


You can share the drillbit log file with these as a run thereafter.


Also, Your profile JSONs indicate that you have a fairly slow underlying filesystem.


I'm seeing an average of

3m45s to read 945K rows (2 node setup)

and

2m25s to read 1.5M rows (5node setup)


Your 2node setup shows 6 fragments processing 29 batches; while 5node setup shows 15 fragments processing 46 batches. For the number of rows, the amount of time spent is very high, which makes me believe that your filesystem (Oracle Cloud Storage service) is itself quite slow.

For speeding up execution, you can try changing the planner.width.max_per_node to a higher value (like the number of cores on the node). This should increase parallelization and the utilization of all the cores by Drill.


Kunal Khatua

Engineering

[MapR]<http://www.mapr.com/>

www.mapr.com<http://www.mapr.com/>

________________________________
From: Jeena Vinod <je...@oracle.com>
Sent: Tuesday, February 28, 2017 12:24:52 PM
To: user@drill.apache.org
Subject: RE: Explain Plan for Parquet data is taking a lot of timre

Kindly let know if there are any pointers on how to improve response time for parquet data here.

Regards
Jeena

-----Original Message-----
From: Jeena Vinod
Sent: Tuesday, February 28, 2017 4:25 AM
To: user@drill.apache.org
Subject: RE: Explain Plan for Parquet data is taking a lot of timre

Hi,

I have 2 Drill 1.9 installations. One is a 5 node 32GB cluster and other is a 2 node 16GB cluster. And I am running the same query in both the places.
select * from `testdata` where <condition> limit 100; testdata is 1GB uncompressed parquet data.

The query response time is found as below:
2 node cluster - 13min
5 node cluster - 19min

I was expecting 5 node cluster to be faster, but the results say otherwise.
In the query profile, as expected, 5 node cluster has more minor fragments, but still the scan time is higher. Attached the json profile for both.
Is this in anyway related to the max batches/max records for row group scan?

Any suggestions on how we can get better response time in the 5 node cluster is appreciated.

Regards
Jeena

-----Original Message-----
From: Jeena Vinod
Sent: Sunday, February 26, 2017 2:22 AM
To: user@drill.apache.org
Subject: RE: Explain Plan for Parquet data is taking a lot of timre

Please find attached the full JSON profile.

Regards
Jeena

-----Original Message-----
From: Padma Penumarthy [mailto:ppenumarthy@mapr.com]
Sent: Saturday, February 25, 2017 3:31 AM
To: user@drill.apache.org
Subject: Re: Explain Plan for Parquet data is taking a lot of timre

Yes, please do send the JSON profile.

Thanks,
Padma

> On Feb 24, 2017, at 1:56 PM, Jeena Vinod <je...@oracle.com> wrote:
>
> Thanks for the suggestions.
>
> I did run REFRESH TABLE METADATA command on this path before firing select query.
>
> In Drill 1.9, there is an improvement in performance. I have 1.9 setup on a 2 node 16GB cluster and here select * with limit 100 is taking less time than 1.8, though the number of rows in ParquetGroupScan remains unchanged. Select query is taking around 8 minutes and explain plan took around 7 minutes. Also in the Web console profile, the query stays in the STARTING status for almost 7 minutes.
>
> Query Plan for 1.9:
> 00-00    Screen : rowType = RecordType(ANY *): rowcount = 100.0, cumulative cost = {32810.0 rows, 33110.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1721
> 00-01      Project(*=[$0]) : rowType = RecordType(ANY *): rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1720
> 00-02        SelectionVectorRemover : rowType = (DrillRecordRow[*]): rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1719
> 00-03          Limit(fetch=[100]) : rowType = (DrillRecordRow[*]): rowcount = 100.0, cumulative cost = {32700.0 rows, 33000.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1718
> 00-04            Scan(groupscan=[ParquetGroupScan [entries=[ReadEntryWithPath [path=/testdata/part-r-00000-097f7399-7bfb-4e93-b883-3348655fc658.parquet]], selectionRoot=/testdata, numFiles=1, usedMetadataFile=true, cacheFileRoot=/testdata, columns=[`*`]]]) : rowType = (DrillRecordRow[*]): rowcount = 32600.0, cumulative cost = {32600.0 rows, 32600.0 cpu, 0.0 io, 0.0 network, 0.0 memory}, id = 1717
>
> And from the query profile, it looks like the most time is spent in PARQUET_ROW_GROUP_SCAN. I can attach the full JSON profile if it helps.
>
> Can there be further improvement in performance with 1.9?
>
> Regards
> Jeena
>
>
> -----Original Message-----
> From: Padma Penumarthy [mailto:ppenumarthy@mapr.com]
> Sent: Friday, February 24, 2017 11:22 PM
> To: user@drill.apache.org
> Subject: Re: Explain Plan for Parquet data is taking a lot of timre
>
> Yes, limit is pushed down to parquet reader in 1.9. But, that will not help with planning time.
> It is definitely worth trying with 1.9 though.
>
> Thanks,
> Padma
>
>
>> On Feb 24, 2017, at 7:26 AM, Andries Engelbrecht <ae...@mapr.com> wrote:
>>
>> Looks like the metadata cache is being used  "usedMetadataFile=true, ". But to be sure did you perform a REFRESH TABLE METADATA <path to table> on the parquet data?
>>
>>
>> However it looks like it is reading a full batch " rowcount = 32600.0, cumulative cost = {32600.0 rows, 32600.0"
>>
>>
>> Didn't the limit operator get pushed down to the parquet reader in 1.9?
>>
>> Perhaps try 1.9 and see if in the ParquetGroupScan the number of rows gets reduced to 100.
>>
>>
>> Can you look in the query profile where time is spend, also how long it takes before the query starts to run in the WebUI profile.
>>
>>
>> Best Regards
>>
>>
>> Andries Engelbrecht
>>
>>
>> Senior Solutions Architect
>>
>> MapR Alliances and Channels Engineering
>>
>>
>> aengelbrecht@mapr.com
>>
>>
>> [1483990071965_mapr-logo-signature.png]
>>
>> ________________________________
>> From: Jinfeng Ni <jn...@apache.org>
>> Sent: Thursday, February 23, 2017 4:53:34 PM
>> To: user
>> Subject: Re: Explain Plan for Parquet data is taking a lot of timre
>>
>> The reason the plan shows only one single parquet file is because 
>> "LIMIT 100" is applied and filter out the rest of them.
>>
>> Agreed that parquet metadata caching might help reduce planning time, 
>> when there are large number of parquet files.
>>
>> On Thu, Feb 23, 2017 at 4:44 PM, rahul challapalli 
>> <ch...@gmail.com> wrote:
>>> You said there are 2144 parquet files but the plan suggests that you 
>>> only have a single parquet file. In any case its a long time to plan the query.
>>> Did you try the metadata caching feature [1]?
>>>
>>> Also how many rowgroups and columns are present in the parquet file?
>>>
>>> [1]
>>> https://drill.apache.org/docs/optimizing-parquet-metadata-reading/
>>>
>>> - Rahul
>>>
>>> On Thu, Feb 23, 2017 at 4:24 PM, Jeena Vinod <je...@oracle.com> wrote:
>>>
>>>> Hi,
>>>>
>>>>
>>>>
>>>> Drill is taking 23 minutes for a simple select * query with limit
>>>> 100 on 1GB uncompressed parquet data. EXPLAIN PLAN for this query 
>>>> is also taking that long(~23 minutes).
>>>>
>>>> Query: select * from <plugin>.root.`testdata` limit 100;
>>>>
>>>> Query  Plan:
>>>>
>>>> 00-00    Screen : rowType = RecordType(ANY *): rowcount = 100.0,
>>>> cumulative cost = {32810.0 rows, 33110.0 cpu, 0.0 io, 0.0 network,
>>>> 0.0 memory}, id = 1429
>>>>
>>>> 00-01      Project(*=[$0]) : rowType = RecordType(ANY *): rowcount =
>>>> 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 io, 0.0 
>>>> network,
>>>> 0.0 memory}, id = 1428
>>>>
>>>> 00-02        SelectionVectorRemover : rowType = (DrillRecordRow[*]):
>>>> rowcount = 100.0, cumulative cost = {32800.0 rows, 33100.0 cpu, 0.0 
>>>> io, 0.0 network, 0.0 memory}, id = 1427
>>>>
>>>> 00-03          Limit(fetch=[100]) : rowType = (DrillRecordRow[*]):
>>>> rowcount = 100.0, cumulative cost = {32700.0 rows, 33000.0 cpu, 0.0 
>>>> io, 0.0 network, 0.0 memory}, id = 1426
>>>>
>>>> 00-04            Scan(groupscan=[ParquetGroupScan
>>>> [entries=[ReadEntryWithPath [path=/testdata/part-r-00000- 
>>>> 097f7399-7bfb-4e93-b883-3348655fc658.parquet]],
>>>> selectionRoot=/testdata, numFiles=1, usedMetadataFile=true, 
>>>> cacheFileRoot=/testdata,
>>>> columns=[`*`]]]) : rowType = (DrillRecordRow[*]): rowcount = 
>>>> 32600.0, cumulative cost = {32600.0 rows, 32600.0 cpu, 0.0 io, 0.0 
>>>> network, 0.0 memory}, id = 1425
>>>>
>>>>
>>>>
>>>> I am using Drill1.8 and it is setup on 5 node 32GB cluster and the 
>>>> data is in Oracle Storage Cloud Service. When I run the same query 
>>>> on 1GB TSV file in this location it is taking only 38 seconds .
>>>>
>>>> Also testdata contains around 2144 .parquet files each around 500KB.
>>>>
>>>>
>>>>
>>>> Is there any additional configuration required for parquet?
>>>>
>>>> Kindly suggest how to improve the response time here.
>>>>
>>>>
>>>>
>>>> Regards
>>>> Jeena
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>