Home | About | Sematext search-lucene.com search-hadoop.com
NEW: Monitor These Apps!
elasticsearch, apache solr, apache hbase, hadoop, redis, casssandra, amazon cloudwatch, mysql, memcached, apache kafka, apache zookeeper, apache storm, ubuntu, centOS, red hat, debian, puppet labs, java, senseiDB
 Search Hadoop and all its subprojects:

Switch to Threaded View
Hive >> mail # user >> Why hadoop job pending for so long?


Copy link to this message
-
Re: Why hadoop job pending for so long?
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.

Regards
Bejoy KS

Sent from handheld, please excuse typos.

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

Hi, all.

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

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:
/data/local/mapred/local/jobTracker/job_201211151751_0015.xml:a
attempt to override final parameter: mapred.local.dir;  Ignoring.
    2012-11-16 15:00:26,687 WARN org.apache.hadoop.conf.Configuration:
/data/local/mapred/local/jobTracker/job_201211151751_0015.xml:a
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:
USER=hadoop  IP=192.168.1.80 OPERATION=SUBMIT_JOB
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
job_201211151751_0015
    2012-11-16 15:00:26,779 INFO
org.apache.hadoop.mapred.JobInProgress: jobToken generated and stored
with users keys in
/data/local/mapred/system/job_201211151751_0015/jobToken
    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
org.apache.hadoop.mapred.JobInProgress:
tip:task_201211151751_0015_m_000000 has split on
node:/default-rack/hadoop02
    2012-11-16 15:00:26,782 INFO
org.apache.hadoop.mapred.JobInProgress: job_201211151751_0015
LOCALITY_WAIT_FACTOR=0.33333334
    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
'tracker_hadoop02:localhost/127.0.0.1:29308'
    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
slots
    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
/data/local/mapred/local/ttprivate/taskTracker/hadoop/jobcache/job_201211151751_0016/attempt_201211151751_0016_m_000002_0/taskjvm.sh
    2012-11-16 15:19:10,545 INFO org.apache.hadoop.mapred.TaskTracker:
JVM with ID: jvm_201211151751_0016_m_-1007622750 given task:
attempt_201211151751_0016_m_000002_0
    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?

Regards,
Cheng Su
NEW: Monitor These Apps!
elasticsearch, apache solr, apache hbase, hadoop, redis, casssandra, amazon cloudwatch, mysql, memcached, apache kafka, apache zookeeper, apache storm, ubuntu, centOS, red hat, debian, puppet labs, java, senseiDB