You are viewing a plain text version of this content. The canonical link for it is here.
Posted to mapreduce-issues@hadoop.apache.org by "Brian Karlak (JIRA)" <ji...@apache.org> on 2009/12/17 07:12:18 UTC
[jira] Created: (MAPREDUCE-1308) reduce tasks stall and are
eventually killed
reduce tasks stall and are eventually killed
--------------------------------------------
Key: MAPREDUCE-1308
URL: https://issues.apache.org/jira/browse/MAPREDUCE-1308
Project: Hadoop Map/Reduce
Issue Type: Bug
Components: tasktracker
Environment: 20-node cluster, 8 cores per machine, 32GB memory, Fedora Linux
Reporter: Brian Karlak
We recently migrated our 0.19.2 cluster from Gentoo Linux to Fedora Linux. Everything was running smoothly before, but now about 5%-10% of our jobs have at least one reduce task that stalls out and is eventually killed with the message:
Task attempt_200912102211_1648_r_000009_0 failed to report status for 6003 seconds. Killing!
The task is then re-launched and completes successfully, usually in a couple of minutes.
This is problematic because our scheduled Hadoop jobs now take an extra hour-and-a-half to run (6000 seconds).
There are no indications in the logs that anything is amiss. The task starts, a small amount of the copy/shuffle runs, and then nothing is else is heard from the task until it is killed. I will attach the relevant parts of the TaskTracker logs in the comments.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (MAPREDUCE-1308) reduce tasks stall and are
eventually killed
Posted by "Brian Karlak (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-1308?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12791973#action_12791973 ]
Brian Karlak commented on MAPREDUCE-1308:
-----------------------------------------
Outside of the time period in question, I do see a few other worrisome log messages in the hadoop (not syslog) files.
In the datanode logs, I see 5 messages (in a 24 hour period) like:
2009-12-17 10:14:13,565 WARN org.apache.hadoop.hdfs.server.datanode.DataNode: DatanodeRegistration(172.29.2.67:50010, storageID=DS-739735928-172.29.2.67-50010-1259798617913, infoPort=50075, ipcPort=50020):Got exception while serving blk_786885296716083440_1313776 to /172.29.2.67:
java.io.IOException: Block blk_786885296716083440_1313776 is not valid.
at org.apache.hadoop.hdfs.server.datanode.FSDataset.getBlockFile(FSDataset.java:731)
at org.apache.hadoop.hdfs.server.datanode.FSDataset.getLength(FSDataset.java:719)
at org.apache.hadoop.hdfs.server.datanode.BlockSender.<init>(BlockSender.java:92)
at org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:172)
at org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:95)
at java.lang.Thread.run(Thread.java:619)
2009-12-17 10:14:13,565 ERROR org.apache.hadoop.hdfs.server.datanode.DataNode: DatanodeRegistration(172.29.2.67:50010, storageID=DS-739735928-172.29.2.67-50010-1259798617913, infoPort=50075, ipcPort=50020):DataXceiver
java.io.IOException: Block blk_786885296716083440_1313776 is not valid.
at org.apache.hadoop.hdfs.server.datanode.FSDataset.getBlockFile(FSDataset.java:731)
at org.apache.hadoop.hdfs.server.datanode.FSDataset.getLength(FSDataset.java:719)
at org.apache.hadoop.hdfs.server.datanode.BlockSender.<init>(BlockSender.java:92)
at org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:172)
at org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:95)
at java.lang.Thread.run(Thread.java:619)
> reduce tasks stall and are eventually killed
> --------------------------------------------
>
> Key: MAPREDUCE-1308
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-1308
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Environment: 20-node cluster, 8 cores per machine, 32GB memory, Fedora Linux
> Reporter: Brian Karlak
>
> We recently migrated our 0.19.2 cluster from Gentoo Linux to Fedora Linux. Everything was running smoothly before, but now about 5%-10% of our jobs have at least one reduce task that stalls out and is eventually killed with the message:
> Task attempt_200912102211_1648_r_000009_0 failed to report status for 6003 seconds. Killing!
> The task is then re-launched and completes successfully, usually in a couple of minutes.
> This is problematic because our scheduled Hadoop jobs now take an extra hour-and-a-half to run (6000 seconds).
> There are no indications in the logs that anything is amiss. The task starts, a small amount of the copy/shuffle runs, and then nothing is else is heard from the task until it is killed. I will attach the relevant parts of the TaskTracker logs in the comments.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (MAPREDUCE-1308) reduce tasks stall and are
eventually killed
Posted by "Brian Karlak (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-1308?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12791974#action_12791974 ]
Brian Karlak commented on MAPREDUCE-1308:
-----------------------------------------
And I see one message for a SocketTimeout:
2009-12-17 06:26:20,082 WARN org.apache.hadoop.hdfs.server.datanode.DataNode: DatanodeRegistration(172.29.2.67:50010, storageID=DS-739735928-172.29.2.67-50010-1259798617913, infoPort=50075, ipcPort=50020):Got exception while serving blk_-7712543153225807619_1300911 to /172.29.2.67:
java.net.SocketTimeoutException: 480000 millis timeout while waiting for channel to be ready for write. ch : java.nio.channels.SocketChannel[connected local=/172.29.2.67:50010 remote=/172.29.2.67:41058]
at org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:185)
at org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:159)
at org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:198)
at org.apache.hadoop.hdfs.server.datanode.BlockSender.sendChunks(BlockSender.java:313)
at org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:400)
at org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:180)
at org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:95)
at java.lang.Thread.run(Thread.java:619)
2009-12-17 06:26:20,082 ERROR org.apache.hadoop.hdfs.server.datanode.DataNode: DatanodeRegistration(172.29.2.67:50010, storageID=DS-739735928-172.29.2.67-50010-1259798617913, infoPort=50075, ipcPort=50020):DataXceiver
java.net.SocketTimeoutException: 480000 millis timeout while waiting for channel to be ready for write. ch : java.nio.channels.SocketChannel[connected local=/172.29.2.67:50010 remote=/172.29.2.67:41058]
at org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:185)
at org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:159)
at org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:198)
at org.apache.hadoop.hdfs.server.datanode.BlockSender.sendChunks(BlockSender.java:313)
at org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:400)
at org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:180)
at org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:95)
at java.lang.Thread.run(Thread.java:619)
> reduce tasks stall and are eventually killed
> --------------------------------------------
>
> Key: MAPREDUCE-1308
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-1308
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Environment: 20-node cluster, 8 cores per machine, 32GB memory, Fedora Linux
> Reporter: Brian Karlak
>
> We recently migrated our 0.19.2 cluster from Gentoo Linux to Fedora Linux. Everything was running smoothly before, but now about 5%-10% of our jobs have at least one reduce task that stalls out and is eventually killed with the message:
> Task attempt_200912102211_1648_r_000009_0 failed to report status for 6003 seconds. Killing!
> The task is then re-launched and completes successfully, usually in a couple of minutes.
> This is problematic because our scheduled Hadoop jobs now take an extra hour-and-a-half to run (6000 seconds).
> There are no indications in the logs that anything is amiss. The task starts, a small amount of the copy/shuffle runs, and then nothing is else is heard from the task until it is killed. I will attach the relevant parts of the TaskTracker logs in the comments.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (MAPREDUCE-1308) reduce tasks stall and are
eventually killed
Posted by "Brian Karlak (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-1308?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12791801#action_12791801 ]
Brian Karlak commented on MAPREDUCE-1308:
-----------------------------------------
The relevant jobtracker logs:
2009-12-17 03:56:05,122 INFO org.apache.hadoop.mapred.JobTracker: Adding task 'attempt_200912102211_1648_r_000009_0' to tip task_200912102211_1648_r_000009, for tracker 'tracker_hadoop0038.data.sjc1.metaweb.com:localhost.localdomain/127.0.0.1:52433'
2009-12-17 05:36:19,032 INFO org.apache.hadoop.mapred.TaskInProgress: Error from attempt_200912102211_1648_r_000009_0: Task attempt_200912102211_1648_r_000009_0 failed to report status for 6003 seconds. Killing!
2009-12-17 05:36:19,033 INFO org.apache.hadoop.mapred.JobTracker: Adding task (cleanup)'attempt_200912102211_1648_r_000009_0' to tip task_200912102211_1648_r_000009, for tracker 'tracker_hadoop0038.data.sjc1.metaweb.com:localhost.localdomain/127.0.0.1:52433'
2009-12-17 05:36:20,581 INFO org.apache.hadoop.mapred.JobTracker: Adding task 'attempt_200912102211_1648_r_000009_1' to tip task_200912102211_1648_r_000009, for tracker 'tracker_hadoop0038.data.sjc1.metaweb.com:localhost.localdomain/127.0.0.1:52433'
2009-12-17 05:36:20,581 INFO org.apache.hadoop.mapred.JobTracker: Removed completed task 'attempt_200912102211_1648_r_000009_0' from 'tracker_hadoop0038.data.sjc1.metaweb.com:localhost.localdomain/127.0.0.1:52433'
2009-12-17 05:40:01,767 INFO org.apache.hadoop.mapred.JobInProgress: Task 'attempt_200912102211_1648_r_000009_1' has completed task_200912102211_1648_r_000009 successfully.
2009-12-17 05:40:04,614 INFO org.apache.hadoop.mapred.JobTracker: Removed completed task 'attempt_200912102211_1648_r_000009_0' from 'tracker_hadoop0038.data.sjc1.metaweb.com:localhost.localdomain/127.0.0.1:52433'
2009-12-17 05:40:04,615 INFO org.apache.hadoop.mapred.JobTracker: Removed completed task 'attempt_200912102211_1648_r_000009_1' from 'tracker_hadoop0038.data.sjc1.metaweb.com:localhost.localdomain/127.0.0.1:52433'
> reduce tasks stall and are eventually killed
> --------------------------------------------
>
> Key: MAPREDUCE-1308
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-1308
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Environment: 20-node cluster, 8 cores per machine, 32GB memory, Fedora Linux
> Reporter: Brian Karlak
>
> We recently migrated our 0.19.2 cluster from Gentoo Linux to Fedora Linux. Everything was running smoothly before, but now about 5%-10% of our jobs have at least one reduce task that stalls out and is eventually killed with the message:
> Task attempt_200912102211_1648_r_000009_0 failed to report status for 6003 seconds. Killing!
> The task is then re-launched and completes successfully, usually in a couple of minutes.
> This is problematic because our scheduled Hadoop jobs now take an extra hour-and-a-half to run (6000 seconds).
> There are no indications in the logs that anything is amiss. The task starts, a small amount of the copy/shuffle runs, and then nothing is else is heard from the task until it is killed. I will attach the relevant parts of the TaskTracker logs in the comments.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (MAPREDUCE-1308) reduce tasks stall and are
eventually killed
Posted by "Arun C Murthy (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-1308?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12791842#action_12791842 ]
Arun C Murthy commented on MAPREDUCE-1308:
------------------------------------------
bq. This is problematic because our scheduled Hadoop jobs now take an extra hour-and-a-half to run (6000 seconds).
First up, this is a per-job config... why is mapred.task.timeout set to 6000s? The default value is 600s.
----
Could you please check the reducer's syslog file to check if there are issues?
> reduce tasks stall and are eventually killed
> --------------------------------------------
>
> Key: MAPREDUCE-1308
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-1308
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Environment: 20-node cluster, 8 cores per machine, 32GB memory, Fedora Linux
> Reporter: Brian Karlak
>
> We recently migrated our 0.19.2 cluster from Gentoo Linux to Fedora Linux. Everything was running smoothly before, but now about 5%-10% of our jobs have at least one reduce task that stalls out and is eventually killed with the message:
> Task attempt_200912102211_1648_r_000009_0 failed to report status for 6003 seconds. Killing!
> The task is then re-launched and completes successfully, usually in a couple of minutes.
> This is problematic because our scheduled Hadoop jobs now take an extra hour-and-a-half to run (6000 seconds).
> There are no indications in the logs that anything is amiss. The task starts, a small amount of the copy/shuffle runs, and then nothing is else is heard from the task until it is killed. I will attach the relevant parts of the TaskTracker logs in the comments.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (MAPREDUCE-1308) reduce tasks stall and are
eventually killed
Posted by "Brian Karlak (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-1308?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12791978#action_12791978 ]
Brian Karlak commented on MAPREDUCE-1308:
-----------------------------------------
And in the tasktracker logs, around the same time but for a different task, I get errors like the one below. There are about 55 of these over a 24-hour period.
2009-12-17 03:56:14,843 WARN org.apache.hadoop.mapred.TaskTracker: getMapOutput(attempt_200912102211_1648_m_000082_0,46) failed :
java.net.SocketException: Connection reset
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:96)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at org.mortbay.http.ChunkingOutputStream.bypassWrite(ChunkingOutputStream.java:151)
at org.mortbay.http.BufferedOutputStream.write(BufferedOutputStream.java:139)
at org.mortbay.http.HttpOutputStream.write(HttpOutputStream.java:423)
at org.mortbay.jetty.servlet.ServletOut.write(ServletOut.java:54)
at org.apache.hadoop.mapred.TaskTracker$MapOutputServlet.doGet(TaskTracker.java:2919)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:689)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:427)
at org.mortbay.jetty.servlet.WebApplicationHandler.dispatch(WebApplicationHandler.java:475)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:567)
at org.mortbay.http.HttpContext.handle(HttpContext.java:1565)
at org.mortbay.jetty.servlet.WebApplicationContext.handle(WebApplicationContext.java:635)
at org.mortbay.http.HttpContext.handle(HttpContext.java:1517)
at org.mortbay.http.HttpServer.service(HttpServer.java:954)
at org.mortbay.http.HttpConnection.service(HttpConnection.java:814)
at org.mortbay.http.HttpConnection.handleNext(HttpConnection.java:981)
at org.mortbay.http.HttpConnection.handle(HttpConnection.java:831)
at org.mortbay.http.SocketListener.handleConnection(SocketListener.java:244)
at org.mortbay.util.ThreadedServer.handle(ThreadedServer.java:357)
at org.mortbay.util.ThreadPool$PoolThread.run(ThreadPool.java:534)
2009-12-17 03:56:14,844 INFO org.apache.hadoop.mapred.TaskTracker.clienttrace: src: 172.29.2.67:50060, dest: 172.29.2.61:17116, bytes: 589824, op: MAPRED_SHUFFLE, cliID: attempt_200912102211_1648_m_000082_0
2009-12-17 03:56:14,844 WARN /: /mapOutput?job=job_200912102211_1648&map=attempt_200912102211_1648_m_000082_0&reduce=46:
java.lang.IllegalStateException: Committed
at org.mortbay.jetty.servlet.ServletHttpResponse.resetBuffer(ServletHttpResponse.java:212)
at org.mortbay.jetty.servlet.ServletHttpResponse.sendError(ServletHttpResponse.java:375)
at org.apache.hadoop.mapred.TaskTracker$MapOutputServlet.doGet(TaskTracker.java:2945)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:689)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:427)
at org.mortbay.jetty.servlet.WebApplicationHandler.dispatch(WebApplicationHandler.java:475)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:567)
at org.mortbay.http.HttpContext.handle(HttpContext.java:1565)
at org.mortbay.jetty.servlet.WebApplicationContext.handle(WebApplicationContext.java:635)
at org.mortbay.http.HttpContext.handle(HttpContext.java:1517)
at org.mortbay.http.HttpServer.service(HttpServer.java:954)
at org.mortbay.http.HttpConnection.service(HttpConnection.java:814)
at org.mortbay.http.HttpConnection.handleNext(HttpConnection.java:981)
at org.mortbay.http.HttpConnection.handle(HttpConnection.java:831)
at org.mortbay.http.SocketListener.handleConnection(SocketListener.java:244)
at org.mortbay.util.ThreadedServer.handle(ThreadedServer.java:357)
at org.mortbay.util.ThreadPool$PoolThread.run(ThreadPool.java:534)
> reduce tasks stall and are eventually killed
> --------------------------------------------
>
> Key: MAPREDUCE-1308
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-1308
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Environment: 20-node cluster, 8 cores per machine, 32GB memory, Fedora Linux
> Reporter: Brian Karlak
>
> We recently migrated our 0.19.2 cluster from Gentoo Linux to Fedora Linux. Everything was running smoothly before, but now about 5%-10% of our jobs have at least one reduce task that stalls out and is eventually killed with the message:
> Task attempt_200912102211_1648_r_000009_0 failed to report status for 6003 seconds. Killing!
> The task is then re-launched and completes successfully, usually in a couple of minutes.
> This is problematic because our scheduled Hadoop jobs now take an extra hour-and-a-half to run (6000 seconds).
> There are no indications in the logs that anything is amiss. The task starts, a small amount of the copy/shuffle runs, and then nothing is else is heard from the task until it is killed. I will attach the relevant parts of the TaskTracker logs in the comments.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (MAPREDUCE-1308) reduce tasks stall and are
eventually killed
Posted by "Brian Karlak (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-1308?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12791965#action_12791965 ]
Brian Karlak commented on MAPREDUCE-1308:
-----------------------------------------
Arun --
Thanks for the pointers. I'm not quite sure how mapred.task.timeout got set incorrectly -- I went through our local SVN repo, and it seems to have been set that way at our site since we were using 0.16.4 back in July 2008. Since it was never an issue until now, we never noticed, I guess. ;-)
Parameter has been modified.
I'll check the syslogs and report back in the next comment.
Brian
> reduce tasks stall and are eventually killed
> --------------------------------------------
>
> Key: MAPREDUCE-1308
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-1308
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Environment: 20-node cluster, 8 cores per machine, 32GB memory, Fedora Linux
> Reporter: Brian Karlak
>
> We recently migrated our 0.19.2 cluster from Gentoo Linux to Fedora Linux. Everything was running smoothly before, but now about 5%-10% of our jobs have at least one reduce task that stalls out and is eventually killed with the message:
> Task attempt_200912102211_1648_r_000009_0 failed to report status for 6003 seconds. Killing!
> The task is then re-launched and completes successfully, usually in a couple of minutes.
> This is problematic because our scheduled Hadoop jobs now take an extra hour-and-a-half to run (6000 seconds).
> There are no indications in the logs that anything is amiss. The task starts, a small amount of the copy/shuffle runs, and then nothing is else is heard from the task until it is killed. I will attach the relevant parts of the TaskTracker logs in the comments.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (MAPREDUCE-1308) reduce tasks stall and are
eventually killed
Posted by "Brian Karlak (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-1308?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12791969#action_12791969 ]
Brian Karlak commented on MAPREDUCE-1308:
-----------------------------------------
I can find no indication of error in the syslog files.
/var/log/messages has only syslog-ng and ntpd messages in the time 03:50 -- 05:40.
> reduce tasks stall and are eventually killed
> --------------------------------------------
>
> Key: MAPREDUCE-1308
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-1308
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Environment: 20-node cluster, 8 cores per machine, 32GB memory, Fedora Linux
> Reporter: Brian Karlak
>
> We recently migrated our 0.19.2 cluster from Gentoo Linux to Fedora Linux. Everything was running smoothly before, but now about 5%-10% of our jobs have at least one reduce task that stalls out and is eventually killed with the message:
> Task attempt_200912102211_1648_r_000009_0 failed to report status for 6003 seconds. Killing!
> The task is then re-launched and completes successfully, usually in a couple of minutes.
> This is problematic because our scheduled Hadoop jobs now take an extra hour-and-a-half to run (6000 seconds).
> There are no indications in the logs that anything is amiss. The task starts, a small amount of the copy/shuffle runs, and then nothing is else is heard from the task until it is killed. I will attach the relevant parts of the TaskTracker logs in the comments.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (MAPREDUCE-1308) reduce tasks stall and are
eventually killed
Posted by "Brian Karlak (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-1308?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12791802#action_12791802 ]
Brian Karlak commented on MAPREDUCE-1308:
-----------------------------------------
The relevant tasktracker logs on the affected tasktracker:
[hadoop@hadoop0038.data.sjc1 logs]$ grep 200912102211_1648_r_000009 hadoop-hadoop-tasktracker-hadoop0038.data.sjc1.metaweb.com.log | grep -v file.out
2009-12-17 03:56:05,124 INFO org.apache.hadoop.mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_200912102211_1648_r_000009_0 task's state:UNASSIGNED
2009-12-17 03:56:05,124 INFO org.apache.hadoop.mapred.TaskTracker: Trying to launch : attempt_200912102211_1648_r_000009_0
2009-12-17 03:56:05,124 INFO org.apache.hadoop.mapred.TaskTracker: In TaskLauncher, current free slots : 8 and trying to launch attempt_200912102211_1648_r_000009_0
2009-12-17 03:56:06,155 INFO org.apache.hadoop.mapred.TaskTracker: JVM with ID: jvm_200912102211_1648_r_1323622642 given task: attempt_200912102211_1648_r_000009_0
2009-12-17 03:56:12,611 INFO org.apache.hadoop.mapred.TaskTracker: attempt_200912102211_1648_r_000009_0 0.014619883% reduce > copy (60 of 1368 at 4.35 MB/s) >
2009-12-17 05:36:15,959 INFO org.apache.hadoop.mapred.TaskTracker: attempt_200912102211_1648_r_000009_0: Task attempt_200912102211_1648_r_000009_0 failed to report status for 6003 seconds. Killing!
2009-12-17 05:36:16,030 INFO org.apache.hadoop.mapred.TaskTracker: About to purge task: attempt_200912102211_1648_r_000009_0
2009-12-17 05:36:16,030 INFO org.apache.hadoop.mapred.TaskRunner: attempt_200912102211_1648_r_000009_0 done; removing files.
2009-12-17 05:36:19,031 INFO org.apache.hadoop.mapred.TaskRunner: attempt_200912102211_1648_r_000009_0 done; removing files.
2009-12-17 05:36:19,036 INFO org.apache.hadoop.mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_200912102211_1648_r_000009_0 task's state:FAILED_UNCLEAN
2009-12-17 05:36:19,036 INFO org.apache.hadoop.mapred.TaskTracker: Trying to launch : attempt_200912102211_1648_r_000009_0
2009-12-17 05:36:19,036 INFO org.apache.hadoop.mapred.TaskTracker: In TaskLauncher, current free slots : 8 and trying to launch attempt_200912102211_1648_r_000009_0
2009-12-17 05:36:20,230 INFO org.apache.hadoop.mapred.TaskTracker: JVM with ID: jvm_200912102211_1648_r_2026654121 given task: attempt_200912102211_1648_r_000009_0
2009-12-17 05:36:20,572 INFO org.apache.hadoop.mapred.TaskTracker: attempt_200912102211_1648_r_000009_0 0.0%
2009-12-17 05:36:20,577 INFO org.apache.hadoop.mapred.TaskTracker: attempt_200912102211_1648_r_000009_0 0.0% cleanup
2009-12-17 05:36:20,578 INFO org.apache.hadoop.mapred.TaskTracker: Task attempt_200912102211_1648_r_000009_0 is done.
2009-12-17 05:36:20,579 INFO org.apache.hadoop.mapred.TaskTracker: reported output size for attempt_200912102211_1648_r_000009_0 was 0
2009-12-17 05:36:20,579 INFO org.apache.hadoop.mapred.TaskRunner: attempt_200912102211_1648_r_000009_0 done; removing files.
2009-12-17 05:36:20,583 INFO org.apache.hadoop.mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_200912102211_1648_r_000009_1 task's state:UNASSIGNED
2009-12-17 05:36:20,584 INFO org.apache.hadoop.mapred.TaskTracker: Trying to launch : attempt_200912102211_1648_r_000009_1
2009-12-17 05:36:20,584 INFO org.apache.hadoop.mapred.TaskTracker: In TaskLauncher, current free slots : 8 and trying to launch attempt_200912102211_1648_r_000009_1
2009-12-17 05:36:21,276 INFO org.apache.hadoop.mapred.TaskTracker: JVM with ID: jvm_200912102211_1648_r_-1445045544 given task: attempt_200912102211_1648_r_000009_1
2009-12-17 05:36:27,586 INFO org.apache.hadoop.mapred.TaskTracker: attempt_200912102211_1648_r_000009_1 0.014619883% reduce > copy (60 of 1368 at 4.35 MB/s) >
2009-12-17 05:36:30,598 INFO org.apache.hadoop.mapred.TaskTracker: attempt_200912102211_1648_r_000009_1 0.019493178% reduce > copy (80 of 1368 at 23.23 MB/s) >
...
The attempt_200912102211_1648_r_000009_1 then runs to completion.
> reduce tasks stall and are eventually killed
> --------------------------------------------
>
> Key: MAPREDUCE-1308
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-1308
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Environment: 20-node cluster, 8 cores per machine, 32GB memory, Fedora Linux
> Reporter: Brian Karlak
>
> We recently migrated our 0.19.2 cluster from Gentoo Linux to Fedora Linux. Everything was running smoothly before, but now about 5%-10% of our jobs have at least one reduce task that stalls out and is eventually killed with the message:
> Task attempt_200912102211_1648_r_000009_0 failed to report status for 6003 seconds. Killing!
> The task is then re-launched and completes successfully, usually in a couple of minutes.
> This is problematic because our scheduled Hadoop jobs now take an extra hour-and-a-half to run (6000 seconds).
> There are no indications in the logs that anything is amiss. The task starts, a small amount of the copy/shuffle runs, and then nothing is else is heard from the task until it is killed. I will attach the relevant parts of the TaskTracker logs in the comments.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.