Hadoop Common
  1. Hadoop Common
  2. HADOOP-2434

MapFile.get on HDFS in TRUNK is WAY!!! slower than 0.15.x

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Blocker Blocker
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 0.16.0
    • Component/s: io
    • Labels:
      None

      Description

      Stall happens down in SequenceFile in the first call to getPos inside readRecordLength. I tried the johano patch from HADOOP-2172 that restores the positional cache but that didn't seem to be the issue here.

      Here is data to support my assertion.

      I wrote a little program to make a MapFile of 1M records. I then did 1M random reads from same file. Below are timings from a 0.15.0 and TRUNK as of this afternoon run.

      0.15.x branch:

      [stack@aa0-000-12 branch-0.15]$ ./bin/hadoop org.apache.hadoop.io.TestMapFile
      .07/12/15 01:29:02 WARN util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
      07/12/15 01:29:02 INFO io.TestMapFile: Writing 1000000 rows to testMapFileRandomAccess
      07/12/15 01:32:04 INFO io.TestMapFile: Writing 1000000 records took 182009ms
      07/12/15 01:32:04 INFO io.TestMapFile: Reading 1000000 random rows
      07/12/15 01:48:02 INFO io.TestMapFile: Reading 1000000 random records took 958243ms
      Time: 1,140.652
      OK (1 test)
      

      For the below test using TRUNK r604352, I amended the test so it output a log message every 100k reads:

      [stack@aa0-000-12 hadoop-trunk]$ ./bin/hadoop org.apache.hadoop.io.TestMapFile
      .07/12/15 01:56:34 WARN util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
      07/12/15 01:56:34 INFO io.TestMapFile: Writing 1000000 rows to testMapFileRandomAccess
      07/12/15 01:59:38 INFO io.TestMapFile: Writing 1000000 records took 183986ms
      07/12/15 01:59:38 INFO io.TestMapFile: Reading 1000000 random rows
      .........
      

      After 20 minutes it still hadn't printed out the 'read 100k messages' (I had to leave – will fill in final figures later)

      1. 2434.patch
        0.6 kB
        stack
      2. TestMapFile.java
        3 kB
        stack
      3. TestMapFile.java
        3 kB
        stack

        Activity

        stack created issue -
        stack made changes -
        Field Original Value New Value
        Attachment TestMapFile.java [ 12371714 ]
        stack made changes -
        Attachment TestMapFile.java [ 12371735 ]
        stack made changes -
        Attachment 2434.patch [ 12371742 ]
        stack made changes -
        Fix Version/s 0.16.0 [ 12312740 ]
        Status Open [ 1 ] Patch Available [ 10002 ]
        Raghu Angadi made changes -
        Assignee stack [ stack ]
        stack made changes -
        Priority Major [ 3 ] Blocker [ 1 ]
        dhruba borthakur made changes -
        Status Patch Available [ 10002 ] Resolved [ 5 ]
        Resolution Fixed [ 1 ]
        Nigel Daley made changes -
        Status Resolved [ 5 ] Closed [ 6 ]

          People

          • Assignee:
            stack
            Reporter:
            stack
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development