hadoop-mapreduce-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Liyin Liang (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (MAPREDUCE-1904) Reducing locking contention in TaskTracker.MapOutputServlet's LocalDirAllocator
Date Wed, 15 Jun 2011 05:53:47 GMT

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

Liyin Liang commented on MAPREDUCE-1904:

This is a great patch. Here is part of the stack when work thread is blocked:
"1797055149@qtp0-98" prio=10 tid=0x0000002aa1a40000 nid=0x333 waiting for monitor entry [0x0000000049dc5000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.apache.hadoop.fs.LocalDirAllocator$AllocatorPerContext.getLocalPathToRead(LocalDirAllocator.java:377)
        - waiting to lock <0x00000000a0000090> (a org.apache.hadoop.fs.LocalDirAllocator$AllocatorPerContext)
        at org.apache.hadoop.fs.LocalDirAllocator.getLocalPathToRead(LocalDirAllocator.java:142)
        at org.apache.hadoop.mapred.TaskTracker$MapOutputServlet.doGet(TaskTracker.java:3086)

I have written a job with one map which output 1M data, and 100 reduces. Each reduce spawn
10 threads to fetch data from map side 3k times just like shuffle phase. When run this job,
most of work threads is blocked on AllocatorPerContext.

With LRUCache, most work threads are blocked on LOG.info() as following stack.
"1793911889@qtp0-101" prio=10 tid=0x0000002aa1530000 nid=0x34f2 waiting for monitor entry
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.apache.log4j.Category.callAppenders(Category.java:204)
        - waiting to lock <0x00000000a01be928> (a org.apache.log4j.spi.RootLogger)
        at org.apache.log4j.Category.forcedLog(Category.java:391)
        at org.apache.log4j.Category.log(Category.java:856)
        at org.apache.commons.logging.impl.Log4JLogger.info(Log4JLogger.java:133)
        at org.apache.hadoop.mapred.TaskTracker$MapOutputServlet.doGet(TaskTracker.java:3246)

With LRUCache + disable LOG.info(): This job takes 3mins, 19sec to run.
Without LRUCache + enable LOG.info(): This job takes just 37sec to run.

b.t.w LRUCache should use *mapId* as key instead of *(jobId + mapId)*. Because jobId is just
part of mapId.

> Reducing locking contention in TaskTracker.MapOutputServlet's LocalDirAllocator
> -------------------------------------------------------------------------------
>                 Key: MAPREDUCE-1904
>                 URL: https://issues.apache.org/jira/browse/MAPREDUCE-1904
>             Project: Hadoop Map/Reduce
>          Issue Type: Improvement
>          Components: tasktracker
>    Affects Versions: 0.20.1
>            Reporter: Rajesh Balamohan
>         Attachments: LocalDirAllocator.JPG, LocalDirAllocator_Monitor.JPG, MAPREDUCE-1904-RC10.patch,
MAPREDUCE-1904-trunk.patch, TaskTracker- yourkit profiler output .jpg, Thread profiler output
showing contention.jpg, profiler output after applying the patch.jpg
> While profiling tasktracker with Sort benchmark, it was observed that threads block on
LocalDirAllocator.getLocalPathToRead() in order to get the index file and temporary map output
> As LocalDirAllocator is tied up with ServetContext,  only one instance would be available
per tasktracker httpserver.  Given the jobid & mapid, LocalDirAllocator retrieves index
file path and temporary map output file path. getLocalPathToRead() is internally synchronized.
> Introducing a LRUCache for this lookup reduces the contention heavily (LRUCache with
key =jobid +mapid and value=PATH to the file). Size of the LRUCache can be varied based on
the environment and I observed a throughput improvement in the order of 4-7% with the introduction
of LRUCache.

This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira


View raw message