Mailing-List: contact mapreduce-issues-help@hadoop.apache.org; run by ezmlm
Precedence: bulk
Reply-To: mapreduce-issues@hadoop.apache.org
Date: Tue, 17 Jan 2012 04:06:40 +0000 (UTC)
From: "Hadoop QA (Commented) (JIRA)" <jira@apache.org>
To: mapreduce-issues@hadoop.apache.org
Message-ID: 
 <120895446.47171.1326773200252.JavaMail.tomcat@hel.zones.apache.org>
Subject: [jira] [Commented] (MAPREDUCE-2450) Calls from running tasks to
 TaskTracker methods sometimes fail and incur a 60s timeout
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 7bit


    [ https://issues.apache.org/jira/browse/MAPREDUCE-2450?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13187428#comment-13187428 ] 

Hadoop QA commented on MAPREDUCE-2450:
--------------------------------------

-1 overall.  Here are the results of testing the latest attachment 
  http://issues.apache.org/jira/secure/attachment/12510796/MAPREDUCE-2450.patch
  against trunk revision .

    +1 @author.  The patch does not contain any @author tags.

    -1 tests included.  The patch doesn't appear to include any new or modified tests.
                        Please justify why no new tests are needed for this patch.
                        Also please list what manual steps were performed to verify this patch.

    +1 javadoc.  The javadoc tool did not generate any warning messages.

    +1 javac.  The applied patch does not increase the total number of javac compiler warnings.

    +1 eclipse:eclipse.  The patch built with eclipse:eclipse.

    +1 findbugs.  The patch does not introduce any new Findbugs (version 1.3.9) warnings.

    +1 release audit.  The applied patch does not increase the total number of release audit warnings.

    +1 core tests.  The patch passed unit tests in .

    +1 contrib tests.  The patch passed contrib unit tests.

Test results: https://builds.apache.org/job/PreCommit-MAPREDUCE-Build/1617//testReport/
Console output: https://builds.apache.org/job/PreCommit-MAPREDUCE-Build/1617//console

This message is automatically generated.
                
> Calls from running tasks to TaskTracker methods sometimes fail and incur a 60s timeout
> --------------------------------------------------------------------------------------
>
>                 Key: MAPREDUCE-2450
>                 URL: https://issues.apache.org/jira/browse/MAPREDUCE-2450
>             Project: Hadoop Map/Reduce
>          Issue Type: Bug
>    Affects Versions: 0.23.0
>            Reporter: Matei Zaharia
>            Assignee: Rajesh Balamohan
>         Attachments: HADOOP-5380.Y.20.branch.patch, HADOOP-5380.patch, HADOOP_5380-Y.0.20.20x.patch, MAPREDUCE-2450.patch, mapreduce-2450.patch
>
>
> I'm seeing some map tasks in my jobs take 1 minute to commit after they finish the map computation. On the map side, the output looks like this:
> <code>
> 2009-03-02 21:30:54,384 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Cannot initialize JVM Metrics with processName=MAP, sessionId= - already initialized
> 2009-03-02 21:30:54,437 INFO org.apache.hadoop.mapred.MapTask: numReduceTasks: 800
> 2009-03-02 21:30:54,437 INFO org.apache.hadoop.mapred.MapTask: io.sort.mb = 300
> 2009-03-02 21:30:55,493 INFO org.apache.hadoop.mapred.MapTask: data buffer = 239075328/298844160
> 2009-03-02 21:30:55,494 INFO org.apache.hadoop.mapred.MapTask: record buffer = 786432/983040
> 2009-03-02 21:31:00,381 INFO org.apache.hadoop.mapred.MapTask: Starting flush of map output
> 2009-03-02 21:31:07,892 INFO org.apache.hadoop.mapred.MapTask: Finished spill 0
> 2009-03-02 21:31:07,951 INFO org.apache.hadoop.mapred.TaskRunner: Task:attempt_200903022127_0001_m_003163_0 is done. And is in the process of commiting
> 2009-03-02 21:32:07,949 INFO org.apache.hadoop.mapred.TaskRunner: Communication exception: java.io.IOException: Call to /127.0.0.1:50311 failed on local exception: java.nio.channels.ClosedChannelException
> 	at org.apache.hadoop.ipc.Client.wrapException(Client.java:765)
> 	at org.apache.hadoop.ipc.Client.call(Client.java:733)
> 	at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
> 	at org.apache.hadoop.mapred.$Proxy0.ping(Unknown Source)
> 	at org.apache.hadoop.mapred.Task$TaskReporter.run(Task.java:525)
> 	at java.lang.Thread.run(Thread.java:619)
> Caused by: java.nio.channels.ClosedChannelException
> 	at java.nio.channels.spi.AbstractSelectableChannel.register(AbstractSelectableChannel.java:167)
> 	at java.nio.channels.SelectableChannel.register(SelectableChannel.java:254)
> 	at org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:331)
> 	at org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:157)
> 	at org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:155)
> 	at org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:128)
> 	at java.io.FilterInputStream.read(FilterInputStream.java:116)
> 	at org.apache.hadoop.ipc.Client$Connection$PingInputStream.read(Client.java:276)
> 	at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
> 	at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
> 	at java.io.DataInputStream.readInt(DataInputStream.java:370)
> 	at org.apache.hadoop.ipc.Client$Connection.receiveResponse(Client.java:501)
> 	at org.apache.hadoop.ipc.Client$Connection.run(Client.java:446)
> 2009-03-02 21:32:07,953 INFO org.apache.hadoop.mapred.TaskRunner: Task 'attempt_200903022127_0001_m_003163_0' done.
> </code>
> In the TaskTracker log, it looks like this:
> <code>
> 2009-03-02 21:31:08,110 WARN org.apache.hadoop.ipc.Server: IPC Server Responder, call ping(attempt_200903022127_0001_m_003163_0) from 127.0.0.1:56884: output error
> 2009-03-02 21:31:08,111 INFO org.apache.hadoop.ipc.Server: IPC Server handler 10 on 50311 caught: java.nio.channels.ClosedChannelException
>     at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:126)
>     at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:324)    at org.apache.hadoop.ipc.Server.channelWrite(Server.java:1195)
>     at org.apache.hadoop.ipc.Server.access$1900(Server.java:77)
>     at org.apache.hadoop.ipc.Server$Responder.processResponse(Server.java:613)
>     at org.apache.hadoop.ipc.Server$Responder.doRespond(Server.java:677)
>     at org.apache.hadoop.ipc.Server$Handler.run(Server.java:981)
> </code>
> Note that the task actually seemed to commit - it didn't get speculatively executed or anything. However, the job wasn't able to continue until this one task was done. Both parties seem to think the channel was closed. How does the channel get closed externally? If closing it from outside is unavoidable, maybe the right thing to do is to set a much lower timeout, because 1 minute delay can be pretty significant for a small job.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira