how to check what goes wrong with failed pig jobs?

[jiang licht <li...@yahoo.com>]

I have a pig job which supposes to save some result in the hdfs. Most time it runs just fine. But it failed once and no result was generated. There was no dead node. And namenode, tasktracker and jobtracker were all up and running. The following is the pig job log. It did show some exception but that is not logged as an error. And no obvious clues can be found in logs of nn, tasktracker and jobtracker when the failure happened.

So, how to tell what goes wrong when things like this happens? Any pointer and thoughts? Thanks,
 
2010-06-22 01:45:06,029 [main] INFO  org.apache.pig.Main - Logging error messages to: /tmp/logs/pig_1277189106028.log
2010-06-22 01:45:06,516 [main] INFO  org.apache.pig.backend.hadoop.executionengine.HExecutionEngine - Connecting to hadoop file system at: hdfs://hadoopmaster:50001
2010-06-22 01:45:07,211 [main] INFO  org.apache.pig.backend.hadoop.executionengine.HExecutionEngine - Connecting to map-reduce job tracker at: hadoopmaster:50002
2010-06-22 01:45:07,910 [main] INFO  org.apache.pig.backend.hadoop.executionengine.mapReduceLayer.MultiQueryOptimizer - MR plan size before optimization: 3
2010-06-22 01:45:07,911 [main] INFO  org.apache.pig.backend.hadoop.executionengine.mapReduceLayer.MultiQueryOptimizer - Merged 2 map-only splittees.
2010-06-22 01:45:07,911 [main] INFO  org.apache.pig.backend.hadoop.executionengine.mapReduceLayer.MultiQueryOptimizer - Merged 2 out of total 2 splittees.
2010-06-22 01:45:07,911 [main] INFO  org.apache.pig.backend.hadoop.executionengine.mapReduceLayer.MultiQueryOptimizer - MR plan size after optimization: 1
2010-06-22 01:45:09,163 [main] INFO  org.apache.pig.backend.hadoop.executionengine.mapReduceLayer.JobControlCompiler - Setting up multi store job
2010-06-22 01:45:09,171 [main] INFO  org.apache.pig.backend.hadoop.executionengine.mapReduceLayer.JobControlCompiler - Setting identity combiner class.
2010-06-22 01:45:09,270 [Thread-10] WARN  org.apache.hadoop.mapred.JobClient - Use GenericOptionsParser for parsing the arguments. Applications should implement Tool for the same.
2010-06-22 01:45:09,767 [main] INFO  org.apache.pig.backend.hadoop.executionengine.mapReduceLayer.MapReduceLauncher - 0% complete
2010-06-22 01:46:13,385 [Thread-15] INFO  org.apache.hadoop.hdfs.DFSClient - Exception in createBlockOutputStream java.io.IOException: Bad connect ack with firstBadLink 192.168.133.13:50010
2010-06-22 01:46:13,399 [Thread-15] INFO  org.apache.hadoop.hdfs.DFSClient - Abandoning block blk_-3238247195956896658_451260
2010-06-22 01:46:13,402 [Thread-15] INFO  org.apache.hadoop.hdfs.DFSClient - Waiting to find target node: 192.168.133.12:50010
2010-06-22 01:47:19,410 [Thread-15] INFO  org.apache.hadoop.hdfs.DFSClient - Exception in createBlockOutputStream java.io.IOException: Bad connect ack with firstBadLink 192.168.133.12:50010
2010-06-22 01:47:19,410 [Thread-15] INFO  org.apache.hadoop.hdfs.DFSClient - Abandoning block blk_-8967610649184651127_451260
2010-06-22 01:47:19,412 [Thread-15] INFO  org.apache.hadoop.hdfs.DFSClient - Waiting to find target node: 192.168.133.11:50010
2010-06-22 01:48:26,267 [Thread-21] INFO  org.apache.hadoop.hdfs.DFSClient - Exception in createBlockOutputStream java.io.IOException: Bad connect ack with firstBadLink 192.168.133.3:50010
2010-06-22 01:48:26,267 [Thread-21] INFO  org.apache.hadoop.hdfs.DFSClient - Abandoning block blk_9202045569864855438_451264
2010-06-22 01:48:26,283 [Thread-21] INFO  org.apache.hadoop.hdfs.DFSClient - Waiting to find target node: 192.168.133.12:50010
2010-06-22 01:49:32,317 [Thread-21] INFO  org.apache.hadoop.hdfs.DFSClient - Exception in createBlockOutputStream java.io.IOException: Bad connect ack with firstBadLink 192.168.133.3:50010
2010-06-22 01:49:32,317 [Thread-21] INFO  org.apache.hadoop.hdfs.DFSClient - Abandoning block blk_62775741158062430_451266
2010-06-22 01:49:32,320 [Thread-21] INFO  org.apache.hadoop.hdfs.DFSClient - Waiting to find target node: 192.168.133.5:50010
2010-06-22 01:50:38,326 [Thread-21] INFO  org.apache.hadoop.hdfs.DFSClient - Exception in createBlockOutputStream java.io.IOException: Bad connect ack with firstBadLink 192.168.133.11:50010
2010-06-22 01:50:38,326 [Thread-21] INFO  org.apache.hadoop.hdfs.DFSClient - Abandoning block blk_4600730976353859294_451267
2010-06-22 01:50:38,328 [Thread-21] INFO  org.apache.hadoop.hdfs.DFSClient - Waiting to find target node: 192.168.133.10:50010
2010-06-22 01:51:44,338 [Thread-21] INFO  org.apache.hadoop.hdfs.DFSClient - Exception in createBlockOutputStream java.io.IOException: Bad connect ack with firstBadLink 192.168.133.11:50010
2010-06-22 01:51:44,385 [Thread-21] INFO  org.apache.hadoop.hdfs.DFSClient - Abandoning block blk_274719573196033811_451267
2010-06-22 01:51:44,387 [Thread-21] INFO  org.apache.hadoop.hdfs.DFSClient - Waiting to find target node: 192.168.133.12:50010
2010-06-22 01:51:50,389 [Thread-21] WARN  org.apache.hadoop.hdfs.DFSClient - DataStreamer Exception: java.io.IOException: Unable to create new block.
    at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.nextBlockOutputStream(DFSClient.java:2812)
    at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.access$2000(DFSClient.java:2076)
    at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.run(DFSClient.java:2262)

2010-06-22 01:51:50,390 [Thread-21] WARN  org.apache.hadoop.hdfs.DFSClient - Error Recovery for block blk_274719573196033811_451267 bad datanode[1] nodes == null
2010-06-22 01:51:50,390 [Thread-21] WARN  org.apache.hadoop.hdfs.DFSClient - Could not get block locations. Source file "/hadoop/hadoop-hadoop/mapred/system/job_201006211221_0037/job.xml" - Aborting...
ERROR:  'Bad connect ack with firstBadLink 192.168.133.11:50010'
2010-06-22 01:51:50,620 [main] INFO  org.apache.pig.backend.hadoop.executionengine.mapReduceLayer.MapReduceLauncher - 100% complete
2010-06-22 01:51:50,621 [main] INFO  org.apache.pig.backend.hadoop.executionengine.mapReduceLayer.MapReduceLauncher - Success!

--Michael