[TAJO-1056] Wrong resource release or wrong task scheduling

• Type: Bug
• Status: Resolved
• Priority: Blocker
• Resolution: Fixed
• Affects Version/s: 0.9.0, block_iteration
• Fix Version/s: 0.9.0
• Assignee: Jinho Kim
• Reporter: Hyunsik Choi
• Created: 19/Sep/14 22:27
• Updated: 21/Sep/14 18:37
• Resolved: 20/Sep/14 07:37

Description

Please take a look at the following log:

The worker takes shouldDie message and then it removes ExecutionBlockContext with its resources. But, following tasks which belong to this execution block are still scheduled to this worker and they causes NPE.

2014-09-20 07:05:21,894 INFO org.apache.tajo.worker.Task: ==================================
2014-09-20 07:05:21,894 INFO org.apache.tajo.worker.Task: * Subquery ta_1411164263773_0003_000001_000013_00 is initialized
2014-09-20 07:05:21,894 INFO org.apache.tajo.worker.Task: * InterQuery: true, Use RANGE_SHUFFLE shuffle, Fragments (num: 1), Fetches (total:0) :
2014-09-20 07:05:21,894 INFO org.apache.tajo.worker.Task: * Local task dir: file:/data01/tajo/data/q_1411164263773_0003/output/1/13_0
2014-09-20 07:05:21,894 INFO org.apache.tajo.worker.Task: ==================================
2014-09-20 07:05:21,895 INFO org.apache.tajo.worker.TaskAttemptContext: Query status of ta_1411164263773_0003_000001_000013_00 is changed to TA_RUNNING
2014-09-20 07:05:21,895 INFO org.apache.tajo.worker.TaskRunner: Accumulated Received Task: 1
2014-09-20 07:05:21,895 INFO org.apache.tajo.worker.TaskRunner: Initializing: ta_1411164263773_0003_000001_000017_00
2014-09-20 07:05:21,895 INFO org.apache.tajo.worker.TaskAttemptContext: Query status of ta_1411164263773_0003_000001_000016_00 is changed to TA_PENDING
2014-09-20 07:05:21,895 INFO org.apache.tajo.worker.Task: ==================================
2014-09-20 07:05:21,895 INFO org.apache.tajo.worker.Task: * Subquery ta_1411164263773_0003_000001_000016_00 is initialized
2014-09-20 07:05:21,895 INFO org.apache.tajo.worker.Task: * InterQuery: true, Use RANGE_SHUFFLE shuffle, Fragments (num: 1), Fetches (total:0) :
2014-09-20 07:05:21,895 INFO org.apache.tajo.worker.Task: * Local task dir: file:/data09/tajo/data/q_1411164263773_0003/output/1/16_0
2014-09-20 07:05:21,895 INFO org.apache.tajo.worker.Task: ==================================2014-09-20 07:05:21,896 INFO org.apache.tajo.worker.TaskAttemptContext: Query status of ta_1411164263773_0003_000001_000016_00 is changed to TA_RUNNING
2014-09-20 07:05:21,898 INFO org.apache.tajo.worker.TaskRunner: Received ShouldDie flag:eb_1411164263773_0003_000001,container_1411164263773_0003_01_000063
2014-09-20 07:05:21,898 INFO org.apache.tajo.worker.TaskRunner: Stop TaskRunner: eb_1411164263773_0003_000001,container_1411164263773_0003_01_000063
2014-09-20 07:05:21,898 INFO org.apache.tajo.worker.TaskRunnerManager: Stop Task:eb_1411164263773_0003_000001,container_1411164263773_0003_01_00006
3
2014-09-20 07:05:21,899 INFO org.apache.tajo.worker.TaskRunnerManager: ======================== Processing eb_1411164263773_0003_000001 of type STO
P
2014-09-20 07:05:21,899 INFO org.apache.tajo.storage.HashShuffleAppenderManager: Close HashShuffleAppender:eb_1411164263773_0003_000001, not a hash shuffle
2014-09-20 07:05:21,899 INFO org.apache.tajo.worker.TaskAttemptContext: Query status of ta_1411164263773_0003_000001_000006_00 is changed to TA_FAILED
2014-09-20 07:05:21,899 INFO org.apache.tajo.worker.TaskAttemptContext: Query status of ta_1411164263773_0003_000001_000016_00 is changed to TA_FAILED
2014-09-20 07:05:21,899 INFO org.apache.tajo.worker.TaskAttemptContext: Query status of ta_1411164263773_0003_000001_000009_00 is changed to TA_FAILED
2014-09-20 07:05:21,899 INFO org.apache.tajo.worker.TaskAttemptContext: Query status of ta_1411164263773_0003_000001_000011_00 is changed to TA_FAILED
2014-09-20 07:05:21,899 INFO org.apache.tajo.worker.TaskAttemptContext: Query status of ta_1411164263773_0003_000001_000013_00 is changed to TA_FAILED
2014-09-20 07:05:21,899 INFO org.apache.tajo.storage.HashShuffleAppenderManager: Close HashShuffleAppender:eb_1411164263773_0003_000001, not a hash shuffle
2014-09-20 07:05:21,899 INFO org.apache.tajo.worker.TaskRunnerManager: Stopped execution block:eb_1411164263773_0003_000001
2014-09-20 07:05:21,900 INFO org.apache.tajo.worker.TaskAttemptContext: Query status of ta_1411164263773_0003_000001_000017_00 is changed to TA_PENDING
2014-09-20 07:05:21,900 INFO org.apache.tajo.worker.Task: ==================================
2014-09-20 07:05:21,900 INFO org.apache.tajo.worker.Task: * Subquery ta_1411164263773_0003_000001_000017_00 is initialized
2014-09-20 07:05:21,901 INFO org.apache.tajo.worker.Task: * InterQuery: true, Use RANGE_SHUFFLE shuffle, Fragments (num: 1), Fetches (total:0) :
2014-09-20 07:05:21,901 INFO org.apache.tajo.worker.Task: * Local task dir: file:/data07/tajo/data/q_1411164263773_0003/output/1/17_0
2014-09-20 07:05:21,901 ERROR org.apache.tajo.worker.Task: >>>>>>>>> compilationContext is NULL
java.lang.NullPointerException: >>>>>>>>> compilationContext is NULL
        at org.apache.tajo.worker.ExecutionBlockSharedResource.getCompiledComparator(ExecutionBlockSharedResource.java:121)
        at org.apache.tajo.engine.planner.physical.SortExec.<init>(SortExec.java:48)
        at org.apache.tajo.engine.planner.physical.ExternalSortExec.<init>(ExternalSortExec.java:104)
        at org.apache.tajo.engine.planner.physical.ExternalSortExec.<init>(ExternalSortExec.java:139)
        at org.apache.tajo.engine.planner.PhysicalPlannerImpl.createBestSortPlan(PhysicalPlannerImpl.java:1122)
        at org.apache.tajo.engine.planner.PhysicalPlannerImpl.createSortPlan(PhysicalPlannerImpl.java:1117)
        at org.apache.tajo.engine.planner.PhysicalPlannerImpl.createPlanRecursive(PhysicalPlannerImpl.java:206)
        at org.apache.tajo.engine.planner.PhysicalPlannerImpl.createPlan(PhysicalPlannerImpl.java:87)
        at org.apache.tajo.worker.TajoQueryEngine.createPlan(TajoQueryEngine.java:44)
        at org.apache.tajo.worker.Task.run(Task.java:434)