Uploaded image for project: 'Hadoop Common'
  1. Hadoop Common
  2. HADOOP-5318

Poor IO Performance due to AtomicLong operations

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Major
    • Resolution: Won't Fix
    • 0.19.0
    • None
    • None
    • None
    • 2x quad core xeon linux 64 bit

    Description

      The AtomicLong operations in counting file system statistics can cause high levels of contention with multiple threads. This test demonstrates having multiple threads writing to different sequence files:

      import java.io.IOException;
      
      import org.apache.hadoop.conf.Configuration;
      import org.apache.hadoop.fs.FileSystem;
      import org.apache.hadoop.fs.Path;
      import org.apache.hadoop.io.ByteWritable;
      import org.apache.hadoop.io.SequenceFile;
      import org.apache.hadoop.io.SequenceFile.Writer;
      import org.apache.hadoop.io.SequenceFile.CompressionType;
      
      
      public class Test {
      	public static void main(String[] args) throws IOException {
      		final Configuration c = new Configuration();
      		final FileSystem fs = FileSystem.get(c);
      		
      		final int NUM = 1000*1000;
      		for (int i = 0; i < Integer.valueOf(args[0]); i ++) {
      			final int ii = i;
      			new Thread(new Runnable() {
      				@Override
      				public void run() {
      					
      					try {
      						Writer f = SequenceFile.createWriter(fs, c, new Path("/test/" + ii ), ByteWritable.class, ByteWritable.class, CompressionType.NONE);
      						ByteWritable v = new ByteWritable();
      						
      						long time = System.currentTimeMillis();
      						for (int i = 0; i < NUM; i ++)
      							f.append(v, v);
      						f.close();
      						long end = System.currentTimeMillis();
      						
      						System.out.printf("%d opartions in %d msec. %f/second\n", NUM, end - time, (float)(1000 * NUM)/(end - time));
      						
      					} catch (Exception e) {
      						// TODO Auto-generated catch block
      						e.printStackTrace();
      					}
      					
      				}
      			}).start();
      		}
      	}
      }
      

      The results of this benchmark are

      ==== 1 threads ====
      1000000 opartions in 1431 msec. 698812.000000/second
      ==== 2 threads ====
      1000000 opartions in 3001 msec. 333222.250000/second
      1000000 opartions in 2985 msec. 335008.375000/second
      ==== 3 threads ====
      1000000 opartions in 4923 msec. 203128.171875/second
      1000000 opartions in 4924 msec. 203086.921875/second
      1000000 opartions in 4981 msec. 200762.906250/second
      ==== 4 threads ====
      1000000 opartions in 6716 msec. 148898.156250/second
      1000000 opartions in 7048 msec. 141884.218750/second
      1000000 opartions in 7342 msec. 136202.671875/second
      1000000 opartions in 7344 msec. 136165.578125/second
      ==== 5 threads ====
      1000000 opartions in 10366 msec. 96469.226563/second
      1000000 opartions in 11085 msec. 90212.000000/second
      1000000 opartions in 11121 msec. 89919.968750/second
      1000000 opartions in 11464 msec. 87229.585938/second
      1000000 opartions in 11538 msec. 86670.132813/second
      ==== 6 threads ====
      1000000 opartions in 16513 msec. 60558.347656/second
      1000000 opartions in 17704 msec. 56484.410156/second
      1000000 opartions in 18219 msec. 54887.753906/second
      1000000 opartions in 18550 msec. 53908.355469/second
      1000000 opartions in 18605 msec. 53748.992188/second
      1000000 opartions in 18663 msec. 53581.953125/second
      ==== 7 threads ====
      1000000 opartions in 22207 msec. 45030.847656/second
      1000000 opartions in 23275 msec. 42964.554688/second
      1000000 opartions in 23484 msec. 42582.183594/second
      1000000 opartions in 24378 msec. 41020.593750/second
      1000000 opartions in 24425 msec. 40941.656250/second
      1000000 opartions in 24533 msec. 40761.421875/second
      1000000 opartions in 24645 msec. 40576.183594/second
      ==== 8 threads ====
      1000000 opartions in 26375 msec. 37914.691406/second
      1000000 opartions in 26420 msec. 37850.113281/second
      1000000 opartions in 26532 msec. 37690.335938/second
      1000000 opartions in 26670 msec. 37495.312500/second
      1000000 opartions in 29772 msec. 33588.605469/second
      1000000 opartions in 29859 msec. 33490.738281/second
      1000000 opartions in 30098 msec. 33224.800781/second
      1000000 opartions in 30082 msec. 33242.468750/second
      

      However, if I comment out the file system statistics increments, the benchmark improves to:

      ==== 1 threads ====
      1000000 opartions in 1194 msec. 837520.937500/second
      ==== 2 threads ====
      1000000 opartions in 1433 msec. 697836.687500/second
      1000000 opartions in 1433 msec. 697836.687500/second
      ==== 3 threads ====
      1000000 opartions in 1643 msec. 608642.750000/second
      1000000 opartions in 1643 msec. 608642.750000/second
      1000000 opartions in 1639 msec. 610128.125000/second
      ==== 4 threads ====
      1000000 opartions in 1886 msec. 530222.687500/second
      1000000 opartions in 1886 msec. 530222.687500/second
      1000000 opartions in 1886 msec. 530222.687500/second
      1000000 opartions in 1899 msec. 526592.937500/second
      ==== 5 threads ====
      1000000 opartions in 2065 msec. 484261.500000/second
      1000000 opartions in 2066 msec. 484027.093750/second
      1000000 opartions in 2067 msec. 483792.937500/second
      1000000 opartions in 2066 msec. 484027.093750/second
      1000000 opartions in 2066 msec. 484027.093750/second
      ==== 6 threads ====
      1000000 opartions in 2151 msec. 464900.031250/second
      1000000 opartions in 2111 msec. 473709.156250/second
      1000000 opartions in 2153 msec. 464468.187500/second
      1000000 opartions in 2114 msec. 473036.906250/second
      1000000 opartions in 2113 msec. 473260.781250/second
      1000000 opartions in 2112 msec. 473484.843750/second
      ==== 7 threads ====
      1000000 opartions in 2368 msec. 422297.312500/second
      1000000 opartions in 2334 msec. 428449.000000/second
      1000000 opartions in 2332 msec. 428816.468750/second
      1000000 opartions in 2330 msec. 429184.562500/second
      1000000 opartions in 2332 msec. 428816.468750/second
      1000000 opartions in 2375 msec. 421052.625000/second
      1000000 opartions in 2394 msec. 417710.937500/second
      ==== 8 threads ====
      1000000 opartions in 2517 msec. 397298.375000/second
      1000000 opartions in 2538 msec. 394011.031250/second
      1000000 opartions in 2538 msec. 394011.031250/second
      1000000 opartions in 2538 msec. 394011.031250/second
      1000000 opartions in 2539 msec. 393855.843750/second
      1000000 opartions in 2614 msec. 382555.468750/second
      1000000 opartions in 2666 msec. 375093.781250/second
      1000000 opartions in 2701 msec. 370233.250000/second
      

      Attachments

        1. TestWriteConcurrency.java
          2 kB
          Todd Lipcon
        2. TestWriteConcurrency.java
          2 kB
          Todd Lipcon
        3. TestWriteConcurrency.java
          3 kB
          Todd Lipcon
        4. Rplot001.png
          29 kB
          Todd Lipcon
        5. hadoop-5318.txt
          2 kB
          Todd Lipcon
        6. hadoop-5318.txt
          2 kB
          Todd Lipcon
        7. hadoop-5318.txt
          2 kB
          Todd Lipcon
        8. buffer-output.patch
          0.9 kB
          Ben Maurer
        9. buf.patch
          5 kB
          Ben Maurer

        Issue Links

          Activity

            People

              tlipcon Todd Lipcon
              bmaurer Ben Maurer
              Votes:
              0 Vote for this issue
              Watchers:
              18 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: