Home | About | Sematext search-lucene.com search-hadoop.com
 Search Hadoop and all its subprojects:

Switch to Plain View
Hive, mail # user - Why hadoop job pending for so long?

Cheng Su 2012-11-16, 09:00
Copy link to this message
Re: Why hadoop job pending for so long?
Bejoy KS 2012-11-16, 09:51
Hi Chen

Hope you ensured that you have enough free slots in your queue/pool if you are using fair/capacity scheduler in your cluster.

Some times the job initialization would take some time if there are larger number of partitions and lots of small input files in them.

Bejoy KS

Sent from handheld, please excuse typos.

-----Original Message-----
From: Cheng Su <[EMAIL PROTECTED]>
Date: Fri, 16 Nov 2012 17:00:12
Subject: Why hadoop job pending for so long?

Hi, all.

I am running some hive queries. I use hive 0.9.0 + hadoop

But some of them are pending for quite a long time, say 30min or even longer.
I have enough free map slots.

In the jobtracker logs:

    2012-11-16 15:00:26,686 WARN org.apache.hadoop.conf.Configuration:
attempt to override final parameter: mapred.local.dir;  Ignoring.
    2012-11-16 15:00:26,687 WARN org.apache.hadoop.conf.Configuration:
attempt to override final parameter: mapred.job.tracker;  Ignoring.
    2012-11-16 15:00:26,687 INFO
org.apache.hadoop.mapred.JobInProgress: job_201211151751_0015: nMaps=1
nReduces=1 max=-1
    2012-11-16 15:00:26,687 INFO org.apache.hadoop.mapred.JobTracker:
Job job_201211151751_0015 added successfully for user 'hadoop' to
queue 'default'
    2012-11-16 15:00:26,687 INFO org.apache.hadoop.mapred.AuditLogger:
TARGET=job_201211151751_0015    RESULT=SUCCESS
    2012-11-16 15:00:26,687 INFO org.apache.hadoop.mapred.JobTracker:
Initializing job_201211151751_0015
    2012-11-16 15:00:26,687 INFO
org.apache.hadoop.mapred.JobInProgress: Initializing
    2012-11-16 15:00:26,779 INFO
org.apache.hadoop.mapred.JobInProgress: jobToken generated and stored
with users keys in
    2012-11-16 15:00:26,781 INFO
org.apache.hadoop.mapred.JobInProgress: Input size for job
job_201211151751_0015 = 0. Number of splits = 1
    2012-11-16 15:00:26,781 INFO
tip:task_201211151751_0015_m_000000 has split on
    2012-11-16 15:00:26,782 INFO
org.apache.hadoop.mapred.JobInProgress: job_201211151751_0015
    2012-11-16 15:00:26,782 INFO
org.apache.hadoop.mapred.JobInProgress: Job job_201211151751_0015
initialized successfully with 1 map tasks and 1 reduce tasks.
    2012-11-16 15:00:27,840 INFO org.apache.hadoop.mapred.JobTracker:
Adding task (JOB_SETUP) 'attempt_201211151751_0015_m_000002_0' to tip
task_201211151751_0015_m_000002, for tracker
    2012-11-16 15:00:42,852 INFO
org.apache.hadoop.mapred.JobInProgress: Task
'attempt_201211151751_0015_m_000002_0' has completed
task_201211151751_0015_m_000002 successfully.

In the tasktracker logs:

    2012-11-16 15:18:59,740 INFO org.apache.hadoop.mapred.TaskTracker:
LaunchTaskAction (registerTask): attempt_201211151751_0016_m_000002_0
task's state:UNASSIGNED
    2012-11-16 15:18:59,740 INFO org.apache.hadoop.mapred.TaskTracker:
Trying to launch : attempt_201211151751_0016_m_000002_0 which needs 1
    2012-11-16 15:18:59,740 INFO org.apache.hadoop.mapred.TaskTracker:
In TaskLauncher, current free slots : 9 and trying to launch
attempt_201211151751_0016_m_000002_0 which needs 1 slots
    2012-11-16 15:19:09,185 INFO org.apache.hadoop.mapred.JvmManager:
In JvmRunner constructed JVM ID: jvm_201211151751_0016_m_-1007622750
    2012-11-16 15:19:09,186 INFO org.apache.hadoop.mapred.JvmManager:
JVM Runner jvm_201211151751_0016_m_-1007622750 spawned.
    2012-11-16 15:19:09,187 INFO
org.apache.hadoop.mapred.TaskController: Writing commands to
    2012-11-16 15:19:10,545 INFO org.apache.hadoop.mapred.TaskTracker:
JVM with ID: jvm_201211151751_0016_m_-1007622750 given task:
    2012-11-16 15:19:14,746 INFO org.apache.hadoop.mapred.TaskTracker:
attempt_201211151751_0016_m_000002_0 0.0% setup
    2012-11-16 15:19:14,746 INFO org.apache.hadoop.mapred.TaskTracker:
Task attempt_201211151751_0016_m_000002_0 is done.
    2012-11-16 15:19:14,746 INFO org.apache.hadoop.mapred.TaskTracker:
reported output size for attempt_201211151751_0016_m_000002_0  was -1
    2012-11-16 15:19:15,069 INFO org.apache.hadoop.mapred.JvmManager:
JVM : jvm_201211151751_0016_m_-1007622750 exited with exit code 0.
Number of tasks it ran: 1
    2012-11-16 15:19:17,747 INFO org.apache.hadoop.mapred.TaskTracker:
Received KillTaskAction for task: attempt_201211151751_0016_m_000002_0
    2012-11-16 15:19:17,747 INFO org.apache.hadoop.mapred.TaskTracker:
About to purge task: attempt_201211151751_0016_m_000002_0
    2012-11-16 15:19:17,747 INFO org.apache.hadoop.mapred.IndexCache:
Map ID attempt_201211151751_0016_m_000002_0 not found in cache
What's wrong with the job?

Cheng Su