You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@drill.apache.org by "Melvin Ramos (JIRA)" <ji...@apache.org> on 2018/05/27 03:27:00 UTC

[jira] [Updated] (DRILL-6449) Coordination issue between drillbits

     [ https://issues.apache.org/jira/browse/DRILL-6449?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Melvin Ramos updated DRILL-6449:
--------------------------------
    Description: 
hello

We are evaluating apache drill 1.13.0 to be used on our data lake initiative.

 

Problem:

I was able to select data when I ran small (around 3-50 files) query data which is fine, but when I collapse all on month (2200 different json files) I get into problems.

on initial run it looks like its doing its work, but after executing the actual work, both drillbits seems to wait on each other and see when they are done, and nothing returns on my SQL analyzer query (Dbeaver)

 

Here are last few lines after the run.

Drill Bit 1

 
{code:java}
// code placeholder
long_value: 380172
}
wait_nanos: 42213101
}
start_time: 1527341819358
end_time: 1527341823288
memory_used: 0
max_memory_used: 5997952
endpoint {
address: "ip-10-0-2-209.us-west-2.compute.internal"
user_port: 31010
control_port: 31011
data_port: 31012
version: "1.13.0"
state: ONLINE
}
}
handle {
query_id {
part1: 2663488914051308194
part2: -2037774217156077667
}
major_fragment_id: 1
minor_fragment_id: 4
}

2018-05-26 13:37:03,290 [BitServer-9] DEBUG o.a.d.exec.work.foreman.QueryManager - Foreman is still waiting for completion message from 1 nodes containing 4 fragments

{code}
 

Drill Bit 2

 
{code:java}
// code placeholder
al.config.Limit
2018-05-26 13:37:03,197 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.SelectionVectorRemover
2018-05-26 13:37:03,197 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.SingleSender
2018-05-26 13:37:03,197 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] INFO o.a.d.e.w.fragment.FragmentExecutor - 24f69d0e-3938-1aa2-e3b8-5f2565f6579d:1:7: State change requested RUNNING --> FINISHED
2018-05-26 13:37:03,198 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] INFO o.a.d.e.w.f.FragmentStatusReporter - 24f69d0e-3938-1aa2-e3b8-5f2565f6579d:1:7: State to report: FINISHED
2018-05-26 13:37:03,198 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] DEBUG o.a.d.e.w.f.FragmentStatusReporter - Closing org.apache.drill.exec.work.fragment.FragmentStatusReporter@2552ae4c
2018-05-26 13:37:03,198 [drill-executor-3] INFO o.apache.drill.exec.work.WorkManager - Waiting for 0 queries to complete before shutting down
2018-05-26 13:37:03,199 [drill-executor-3] INFO o.apache.drill.exec.work.WorkManager - Waiting for 1 running fragments to complete before shutting down
2018-05-26 13:37:03,199 [drill-executor-3] INFO o.apache.drill.exec.work.WorkManager - New Fragments or queries are added while drillbit is Shutting down
2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.e.physical.impl.BaseRootExec - closed operator 793318686
2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.store.dfs.easy.EasySubScan
2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.Limit
2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.SelectionVectorRemover
2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.SingleSender
2018-05-26 13:37:03,288 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] INFO o.a.d.e.w.fragment.FragmentExecutor - 24f69d0e-3938-1aa2-e3b8-5f2565f6579d:1:4: State change requested RUNNING --> FINISHED
2018-05-26 13:37:03,288 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] INFO o.a.d.e.w.f.FragmentStatusReporter - 24f69d0e-3938-1aa2-e3b8-5f2565f6579d:1:4: State to report: FINISHED
2018-05-26 13:37:03,288 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.e.w.f.FragmentStatusReporter - Closing org.apache.drill.exec.work.fragment.FragmentStatusReporter@166e8e76

{code}
 

JVM Environment Settings:
{code:java}
// code placeholder
export DRILL_JAVA_OPTS="$DRILL_JAVA_OPTS -Dbounds=false -Ddrill.exec.memory.enable_unsafe_bounds_check=true"


{code}
 

 

  was:
hello

We are evaluating apache drill 1.13.0 to be used on our data lake initiative.

 

Problem:

I was able to select data when I ran small (around 3-50 files) query data which is fine, but when I collapse all on month (2200 different json files) I get into problems.

on initial run it looks like its doing its work, but after executing the actual work, both drillbits seems to wait on each other and see when they are done, and nothing returns on my SQL analyzer query (Dbeaver)

 

Here are last few lines after the run.

Drill Bit 1

 
{code:java}
// code placeholder
long_value: 380172
}
wait_nanos: 42213101
}
start_time: 1527341819358
end_time: 1527341823288
memory_used: 0
max_memory_used: 5997952
endpoint {
address: "ip-10-0-2-209.us-west-2.compute.internal"
user_port: 31010
control_port: 31011
data_port: 31012
version: "1.13.0"
state: ONLINE
}
}
handle {
query_id {
part1: 2663488914051308194
part2: -2037774217156077667
}
major_fragment_id: 1
minor_fragment_id: 4
}

2018-05-26 13:37:03,290 [BitServer-9] DEBUG o.a.d.exec.work.foreman.QueryManager - Foreman is still waiting for completion message from 1 nodes containing 4 fragments

{code}
 

Drill Bit 2

 
{code:java}
// code placeholder
al.config.Limit
2018-05-26 13:37:03,197 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.SelectionVectorRemover
2018-05-26 13:37:03,197 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.SingleSender
2018-05-26 13:37:03,197 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] INFO o.a.d.e.w.fragment.FragmentExecutor - 24f69d0e-3938-1aa2-e3b8-5f2565f6579d:1:7: State change requested RUNNING --> FINISHED
2018-05-26 13:37:03,198 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] INFO o.a.d.e.w.f.FragmentStatusReporter - 24f69d0e-3938-1aa2-e3b8-5f2565f6579d:1:7: State to report: FINISHED
2018-05-26 13:37:03,198 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] DEBUG o.a.d.e.w.f.FragmentStatusReporter - Closing org.apache.drill.exec.work.fragment.FragmentStatusReporter@2552ae4c
2018-05-26 13:37:03,198 [drill-executor-3] INFO o.apache.drill.exec.work.WorkManager - Waiting for 0 queries to complete before shutting down
2018-05-26 13:37:03,199 [drill-executor-3] INFO o.apache.drill.exec.work.WorkManager - Waiting for 1 running fragments to complete before shutting down
2018-05-26 13:37:03,199 [drill-executor-3] INFO o.apache.drill.exec.work.WorkManager - New Fragments or queries are added while drillbit is Shutting down
2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.e.physical.impl.BaseRootExec - closed operator 793318686
2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.store.dfs.easy.EasySubScan
2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.Limit
2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.SelectionVectorRemover
2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.SingleSender
2018-05-26 13:37:03,288 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] INFO o.a.d.e.w.fragment.FragmentExecutor - 24f69d0e-3938-1aa2-e3b8-5f2565f6579d:1:4: State change requested RUNNING --> FINISHED
2018-05-26 13:37:03,288 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] INFO o.a.d.e.w.f.FragmentStatusReporter - 24f69d0e-3938-1aa2-e3b8-5f2565f6579d:1:4: State to report: FINISHED
2018-05-26 13:37:03,288 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.e.w.f.FragmentStatusReporter - Closing org.apache.drill.exec.work.fragment.FragmentStatusReporter@166e8e76

{code}


> Coordination issue between drillbits
> ------------------------------------
>
>                 Key: DRILL-6449
>                 URL: https://issues.apache.org/jira/browse/DRILL-6449
>             Project: Apache Drill
>          Issue Type: Bug
>          Components: Functions - Drill
>    Affects Versions: 1.13.0
>         Environment: My POC info:
>  * 2 EC2 "r4.xlarge" with 30G of memory
>  * both are running zookeeper for load distribution 
>  * both are running drillbits.
>  * Storage
>  ** S3, dfs 
>  * Connection drivers: JDBC
>  * File Types/info: Json, max size between: 7MB - 75MB, and around 2200 different filles 
>  
>            Reporter: Melvin Ramos
>            Priority: Major
>
> hello
> We are evaluating apache drill 1.13.0 to be used on our data lake initiative.
>  
> Problem:
> I was able to select data when I ran small (around 3-50 files) query data which is fine, but when I collapse all on month (2200 different json files) I get into problems.
> on initial run it looks like its doing its work, but after executing the actual work, both drillbits seems to wait on each other and see when they are done, and nothing returns on my SQL analyzer query (Dbeaver)
>  
> Here are last few lines after the run.
> Drill Bit 1
>  
> {code:java}
> // code placeholder
> long_value: 380172
> }
> wait_nanos: 42213101
> }
> start_time: 1527341819358
> end_time: 1527341823288
> memory_used: 0
> max_memory_used: 5997952
> endpoint {
> address: "ip-10-0-2-209.us-west-2.compute.internal"
> user_port: 31010
> control_port: 31011
> data_port: 31012
> version: "1.13.0"
> state: ONLINE
> }
> }
> handle {
> query_id {
> part1: 2663488914051308194
> part2: -2037774217156077667
> }
> major_fragment_id: 1
> minor_fragment_id: 4
> }
> 2018-05-26 13:37:03,290 [BitServer-9] DEBUG o.a.d.exec.work.foreman.QueryManager - Foreman is still waiting for completion message from 1 nodes containing 4 fragments
> {code}
>  
> Drill Bit 2
>  
> {code:java}
> // code placeholder
> al.config.Limit
> 2018-05-26 13:37:03,197 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.SelectionVectorRemover
> 2018-05-26 13:37:03,197 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.SingleSender
> 2018-05-26 13:37:03,197 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] INFO o.a.d.e.w.fragment.FragmentExecutor - 24f69d0e-3938-1aa2-e3b8-5f2565f6579d:1:7: State change requested RUNNING --> FINISHED
> 2018-05-26 13:37:03,198 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] INFO o.a.d.e.w.f.FragmentStatusReporter - 24f69d0e-3938-1aa2-e3b8-5f2565f6579d:1:7: State to report: FINISHED
> 2018-05-26 13:37:03,198 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:7] DEBUG o.a.d.e.w.f.FragmentStatusReporter - Closing org.apache.drill.exec.work.fragment.FragmentStatusReporter@2552ae4c
> 2018-05-26 13:37:03,198 [drill-executor-3] INFO o.apache.drill.exec.work.WorkManager - Waiting for 0 queries to complete before shutting down
> 2018-05-26 13:37:03,199 [drill-executor-3] INFO o.apache.drill.exec.work.WorkManager - Waiting for 1 running fragments to complete before shutting down
> 2018-05-26 13:37:03,199 [drill-executor-3] INFO o.apache.drill.exec.work.WorkManager - New Fragments or queries are added while drillbit is Shutting down
> 2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.e.physical.impl.BaseRootExec - closed operator 793318686
> 2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.store.dfs.easy.EasySubScan
> 2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.Limit
> 2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.SelectionVectorRemover
> 2018-05-26 13:37:03,287 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.exec.ops.OperatorContextImpl - Closing context for org.apache.drill.exec.physical.config.SingleSender
> 2018-05-26 13:37:03,288 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] INFO o.a.d.e.w.fragment.FragmentExecutor - 24f69d0e-3938-1aa2-e3b8-5f2565f6579d:1:4: State change requested RUNNING --> FINISHED
> 2018-05-26 13:37:03,288 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] INFO o.a.d.e.w.f.FragmentStatusReporter - 24f69d0e-3938-1aa2-e3b8-5f2565f6579d:1:4: State to report: FINISHED
> 2018-05-26 13:37:03,288 [24f69d0e-3938-1aa2-e3b8-5f2565f6579d:frag:1:4] DEBUG o.a.d.e.w.f.FragmentStatusReporter - Closing org.apache.drill.exec.work.fragment.FragmentStatusReporter@166e8e76
> {code}
>  
> JVM Environment Settings:
> {code:java}
> // code placeholder
> export DRILL_JAVA_OPTS="$DRILL_JAVA_OPTS -Dbounds=false -Ddrill.exec.memory.enable_unsafe_bounds_check=true"
> {code}
>  
>  



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)