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 "Todd Lipcon (JIRA)" <ji...@apache.org> on 2011/03/16 07:51:29 UTC
[jira] Created: (MAPREDUCE-2389) Spurious EOFExceptions reading
SpillRecord index files
Spurious EOFExceptions reading SpillRecord index files
------------------------------------------------------
Key: MAPREDUCE-2389
URL: https://issues.apache.org/jira/browse/MAPREDUCE-2389
Project: Hadoop Map/Reduce
Issue Type: Bug
Components: tasktracker
Affects Versions: 0.22.0
Environment: Seen on RHEL 5.5, RHEL 6.0, local dirs on ext3, Java 6u20 and 6u24
Reporter: Todd Lipcon
Priority: Critical
In large jobs, I see around 1 shuffle fetch out of every million fetches fail with an EOFException reading the SpillRecord index file. After lots of investigation, including systemtap, it looks like the read() syscall is actually returning a premature "0" result for no reason, so this is likely a kernel or filesystem bug which is exacerbated by some workload the TT does.
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (MAPREDUCE-2389) Spurious EOFExceptions reading
SpillRecord index files
Posted by "Todd Lipcon (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-2389?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13028929#comment-13028929 ]
Todd Lipcon commented on MAPREDUCE-2389:
----------------------------------------
John: as a workaround you can roll back Jetty to 6.1.14 by replacing the jar in the lib directory. Is this causing jobs to fail for you or just the occasional task? What OS and JVM version?
> Spurious EOFExceptions reading SpillRecord index files
> ------------------------------------------------------
>
> Key: MAPREDUCE-2389
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-2389
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Affects Versions: 0.22.0
> Environment: Seen on RHEL 5.5, RHEL 6.0, local dirs on ext3, Java 6u20 and 6u24
> Reporter: Todd Lipcon
> Priority: Critical
> Attachments: stap-output.txt
>
>
> In large jobs, I see around 1 shuffle fetch out of every million fetches fail with an EOFException reading the SpillRecord index file. After lots of investigation, including systemtap, it looks like the read() syscall is actually returning a premature "0" result for no reason, so this is likely a kernel or filesystem bug which is exacerbated by some workload the TT does.
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (MAPREDUCE-2389) Spurious EOFExceptions reading
SpillRecord index files
Posted by "David Spies (Commented) (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-2389?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13257634#comment-13257634 ]
David Spies commented on MAPREDUCE-2389:
----------------------------------------
I've seen the same exact "Map output lost" exception as Todd using Amazon EMR
It wouldn't matter that much except that it occurs during the reduce phase after all the map tasks have already completed. This causes the entire job to stall while the one map task is re-run and it's frequent enough to basically grind the entire job to a halt.
Does anyone know if there's a way to use an older version of Jetty with Amazon EMR?
> Spurious EOFExceptions reading SpillRecord index files
> ------------------------------------------------------
>
> Key: MAPREDUCE-2389
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-2389
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Affects Versions: 0.22.0
> Environment: Seen on RHEL 5.5, RHEL 6.0, local dirs on ext3, Java 6u20 and 6u24
> Reporter: Todd Lipcon
> Priority: Critical
> Attachments: stap-output.txt
>
>
> In large jobs, I see around 1 shuffle fetch out of every million fetches fail with an EOFException reading the SpillRecord index file. After lots of investigation, including systemtap, it looks like the read() syscall is actually returning a premature "0" result for no reason, so this is likely a kernel or filesystem bug which is exacerbated by some workload the TT does.
--
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
[jira] [Commented] (MAPREDUCE-2389) Spurious EOFExceptions reading
SpillRecord index files
Posted by "Nick Jones (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-2389?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13092488#comment-13092488 ]
Nick Jones commented on MAPREDUCE-2389:
---------------------------------------
I also have the same problem on CDH3u0 and was able to workaround it by reverting Jetty 6.1.26 to Jetty 6.1.14.
Environment:
Ubuntu 10.04 x64
Java(TM) SE Runtime Environment (build 1.6.0_15-b03)
> Spurious EOFExceptions reading SpillRecord index files
> ------------------------------------------------------
>
> Key: MAPREDUCE-2389
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-2389
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Affects Versions: 0.22.0
> Environment: Seen on RHEL 5.5, RHEL 6.0, local dirs on ext3, Java 6u20 and 6u24
> Reporter: Todd Lipcon
> Priority: Critical
> Attachments: stap-output.txt
>
>
> In large jobs, I see around 1 shuffle fetch out of every million fetches fail with an EOFException reading the SpillRecord index file. After lots of investigation, including systemtap, it looks like the read() syscall is actually returning a premature "0" result for no reason, so this is likely a kernel or filesystem bug which is exacerbated by some workload the TT does.
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] Commented: (MAPREDUCE-2389) Spurious EOFExceptions reading
SpillRecord index files
Posted by "Todd Lipcon (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-2389?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13007689#comment-13007689 ]
Todd Lipcon commented on MAPREDUCE-2389:
----------------------------------------
Improved my systemtap script to include calls to dup2
[12909] Wed Mar 16 20:59:27 2011: open "/data/4/scratch/todd/haus-mrlocal/taskTracker/todd/jobcache/job_201103161358_0001/attempt_201103161358_0001_m_000339_0/output/file.out.index", O_RDONLY 163
[12909] Wed Mar 16 20:59:27 2011 - dup2 66 -> /data/4/scratch/todd/haus-mrlocal/taskTracker/todd/jobcache/job_201103161358_0001/attempt_201103161358_0001_m_000339_0/output/file.out.index 163
corresponds almost exactly to:
2011-03-16 13:59:27,994 WARN org.apache.hadoop.mapred.TaskTracker: getMapOutput(attempt_201103161358_0001_m_000339_0,22) failed :
java.io.IOException: Invalid request Map Id = attempt_201103161358_0001_m_000339_0 Reducer = 22 Index Info Length = 0
So almost certainly due to a JVM bug with NIO using dup2 in a racy way that overwrites an open fd!
> Spurious EOFExceptions reading SpillRecord index files
> ------------------------------------------------------
>
> Key: MAPREDUCE-2389
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-2389
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Affects Versions: 0.22.0
> Environment: Seen on RHEL 5.5, RHEL 6.0, local dirs on ext3, Java 6u20 and 6u24
> Reporter: Todd Lipcon
> Priority: Critical
> Attachments: stap-output.txt
>
>
> In large jobs, I see around 1 shuffle fetch out of every million fetches fail with an EOFException reading the SpillRecord index file. After lots of investigation, including systemtap, it looks like the read() syscall is actually returning a premature "0" result for no reason, so this is likely a kernel or filesystem bug which is exacerbated by some workload the TT does.
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] Commented: (MAPREDUCE-2389) Spurious EOFExceptions reading
SpillRecord index files
Posted by "Todd Lipcon (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-2389?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13007811#comment-13007811 ]
Todd Lipcon commented on MAPREDUCE-2389:
----------------------------------------
Well, this is interesting. I rolled back my Jetty to 6.1.14 (from 6.1.26) and the problem seems to have gone away.
So, something that changed between Jetty versions seems to trigger the JVM bug more often.
> Spurious EOFExceptions reading SpillRecord index files
> ------------------------------------------------------
>
> Key: MAPREDUCE-2389
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-2389
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Affects Versions: 0.22.0
> Environment: Seen on RHEL 5.5, RHEL 6.0, local dirs on ext3, Java 6u20 and 6u24
> Reporter: Todd Lipcon
> Priority: Critical
> Attachments: stap-output.txt
>
>
> In large jobs, I see around 1 shuffle fetch out of every million fetches fail with an EOFException reading the SpillRecord index file. After lots of investigation, including systemtap, it looks like the read() syscall is actually returning a premature "0" result for no reason, so this is likely a kernel or filesystem bug which is exacerbated by some workload the TT does.
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] Updated: (MAPREDUCE-2389) Spurious EOFExceptions reading
SpillRecord index files
Posted by "Todd Lipcon (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-2389?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Todd Lipcon updated MAPREDUCE-2389:
-----------------------------------
Attachment: stap-output.txt
Attached is the partial output of a systemtap script I wrote which tracks all access to files named *.out.index. You can see the file is opened and successfully read a couple of times, but the third time, it gets a spurious EOF reading the last 8 bytes of the file.
I manually verified this file on disk and it is not actually truncated or modified in any way.
> Spurious EOFExceptions reading SpillRecord index files
> ------------------------------------------------------
>
> Key: MAPREDUCE-2389
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-2389
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Affects Versions: 0.22.0
> Environment: Seen on RHEL 5.5, RHEL 6.0, local dirs on ext3, Java 6u20 and 6u24
> Reporter: Todd Lipcon
> Priority: Critical
> Attachments: stap-output.txt
>
>
> In large jobs, I see around 1 shuffle fetch out of every million fetches fail with an EOFException reading the SpillRecord index file. After lots of investigation, including systemtap, it looks like the read() syscall is actually returning a premature "0" result for no reason, so this is likely a kernel or filesystem bug which is exacerbated by some workload the TT does.
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (MAPREDUCE-2389) Spurious EOFExceptions reading
SpillRecord index files
Posted by "John Novatnack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-2389?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13028905#comment-13028905 ]
John Novatnack commented on MAPREDUCE-2389:
-------------------------------------------
We are also seeing this exception with CDH3 (0.20.2+923.21-1~maverick-cdh3)
> Spurious EOFExceptions reading SpillRecord index files
> ------------------------------------------------------
>
> Key: MAPREDUCE-2389
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-2389
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Affects Versions: 0.22.0
> Environment: Seen on RHEL 5.5, RHEL 6.0, local dirs on ext3, Java 6u20 and 6u24
> Reporter: Todd Lipcon
> Priority: Critical
> Attachments: stap-output.txt
>
>
> In large jobs, I see around 1 shuffle fetch out of every million fetches fail with an EOFException reading the SpillRecord index file. After lots of investigation, including systemtap, it looks like the read() syscall is actually returning a premature "0" result for no reason, so this is likely a kernel or filesystem bug which is exacerbated by some workload the TT does.
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] Commented: (MAPREDUCE-2389) Spurious EOFExceptions reading
SpillRecord index files
Posted by "Todd Lipcon (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-2389?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13007629#comment-13007629 ]
Todd Lipcon commented on MAPREDUCE-2389:
----------------------------------------
Smells sort of similar to this JVM bug: http://bugs.sun.com/view_bug.do?bug_id=6693490
Also reproduced this using a recent build of JDK7, though...
> Spurious EOFExceptions reading SpillRecord index files
> ------------------------------------------------------
>
> Key: MAPREDUCE-2389
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-2389
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Affects Versions: 0.22.0
> Environment: Seen on RHEL 5.5, RHEL 6.0, local dirs on ext3, Java 6u20 and 6u24
> Reporter: Todd Lipcon
> Priority: Critical
> Attachments: stap-output.txt
>
>
> In large jobs, I see around 1 shuffle fetch out of every million fetches fail with an EOFException reading the SpillRecord index file. After lots of investigation, including systemtap, it looks like the read() syscall is actually returning a premature "0" result for no reason, so this is likely a kernel or filesystem bug which is exacerbated by some workload the TT does.
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] Commented: (MAPREDUCE-2389) Spurious EOFExceptions reading
SpillRecord index files
Posted by "Todd Lipcon (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-2389?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13007365#comment-13007365 ]
Todd Lipcon commented on MAPREDUCE-2389:
----------------------------------------
Easiest way to reproduce this is to run a large sleep job on a small cluster. I've been using sleep -mt 1 -rt 1 -m 10000 -r 10000 on 5 node clusters. In such a job I usually see 100-200 of these failures.
Exception trace:
Map output lost, rescheduling: getMapOutput(attempt_201103152313_0001_m_000591_0,437) failed :
java.io.IOException: Error Reading IndexFile
at org.apache.hadoop.mapred.IndexCache.readIndexFileToCache(IndexCache.java:113)
at org.apache.hadoop.mapred.IndexCache.getIndexInformation(IndexCache.java:66)
at org.apache.hadoop.mapred.TaskTracker$MapOutputServlet.doGet(TaskTracker.java:3488)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1221)
at org.apache.hadoop.http.HttpServer$QuotingInputFilter.doFilter(HttpServer.java:816)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1212)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:928)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:549)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:410)
at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
Caused by: java.io.EOFException
at java.io.DataInputStream.readFully(DataInputStream.java:180)
at java.io.DataInputStream.readLong(DataInputStream.java:399)
at org.apache.hadoop.mapred.SpillRecord.<init>(SpillRecord.java:74)
at org.apache.hadoop.mapred.SpillRecord.<init>(SpillRecord.java:54)
at org.apache.hadoop.mapred.IndexCache.readIndexFileToCache(IndexCache.java:109)
... 23 more
> Spurious EOFExceptions reading SpillRecord index files
> ------------------------------------------------------
>
> Key: MAPREDUCE-2389
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-2389
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Affects Versions: 0.22.0
> Environment: Seen on RHEL 5.5, RHEL 6.0, local dirs on ext3, Java 6u20 and 6u24
> Reporter: Todd Lipcon
> Priority: Critical
> Attachments: stap-output.txt
>
>
> In large jobs, I see around 1 shuffle fetch out of every million fetches fail with an EOFException reading the SpillRecord index file. After lots of investigation, including systemtap, it looks like the read() syscall is actually returning a premature "0" result for no reason, so this is likely a kernel or filesystem bug which is exacerbated by some workload the TT does.
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (MAPREDUCE-2389) Spurious EOFExceptions reading
SpillRecord index files
Posted by "John Novatnack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/MAPREDUCE-2389?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13028941#comment-13028941 ]
John Novatnack commented on MAPREDUCE-2389:
-------------------------------------------
Todd: Thanks we will try that. Most of the time it seems to just be causing occasional task failure, but we have also seen the exception happen on a handful of slaves simultaneously and eventually push the jobtracker to run out of heap. Right now our heap is 1gb for the jobtracker with 90 slaves so we'll try increasing it and see if the problem persists with that and the older version of Jetty.
OS: Ubuntu 10.10
JVM:
java version "1.6.0_24"
Java(TM) SE Runtime Environment (build 1.6.0_24-b07)
> Spurious EOFExceptions reading SpillRecord index files
> ------------------------------------------------------
>
> Key: MAPREDUCE-2389
> URL: https://issues.apache.org/jira/browse/MAPREDUCE-2389
> Project: Hadoop Map/Reduce
> Issue Type: Bug
> Components: tasktracker
> Affects Versions: 0.22.0
> Environment: Seen on RHEL 5.5, RHEL 6.0, local dirs on ext3, Java 6u20 and 6u24
> Reporter: Todd Lipcon
> Priority: Critical
> Attachments: stap-output.txt
>
>
> In large jobs, I see around 1 shuffle fetch out of every million fetches fail with an EOFException reading the SpillRecord index file. After lots of investigation, including systemtap, it looks like the read() syscall is actually returning a premature "0" result for no reason, so this is likely a kernel or filesystem bug which is exacerbated by some workload the TT does.
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira