Hadoop benchmarking utilities – Part 1

In the early days of my blog, on May 2016, I published a post called Generating synthetic MapReduce load. It introduced a java program that could run MapReduce jobs inorder to put some load on the cluster. Later that month I published Controling cluster usage with capacity scheduler  which made use of the above program while demonstrating how capacity scheduler handles the load.

At that early stage of my Hadoop journey, I wasn’t aware of some better, built-in solutions for generating load and for benchmarking Hadoop clusters.

There are several Hadoop benchmarking utilities out there and we will examine Six of them in the next two posts (I tried to put them all in one post but it became too long to read comfortably).

The first Three tests are TeraGen, TeraSort and TeraValidate. In the next post, we will examine NNBench, MRBench and TestDFSIO. Although TeraGen can be used alone, this trio is designed to run together in order to get a more complete view of the cluster’s performance.

This trio is called “Tera*” because it produces a Terabyte of data and then runs actions on it. It can be used to create MapReduce jobs and put “artificial” load on a cluster, to measure an compare performance and throughput of different setups on the same cluster, or to compare performance of different clusters.

This is the general flow of this benchmark:

First you run TeraGen, which generates the data, Then you run the TeraSort that sorts the data created in the previous step, and finally you use TeraValidate to validate the sort from previous step. Here is a short description and a run log of each utility. Note that you have to run all those programs as Linux user “hdfs”.

TeraGen

TeraGen runs map tasks to generate the data and will not run any reduce tasks. It’s only purpose is to generate random data. The default data size, as the name of the test implies, is 1TB. However this can be configured through inlineparameters.

This is the command to run. Since I am on Cloudera CDH 5.12, this is the path I used, but It can change according to the Hadoop flavor you use and it’s version. Just run a “find . -name hadoop-mapreduce-examples.jar” on your system to find where the file is.

 hadoop jar /opt/cloudera/parcels/CDH-5.12.0-1.cdh5.12.0.p0.29/lib/hadoop-mapreduce/hadoop-mapreduce-examples.jar teragen 10737418 /teragen 

As you can see, there is the teragen command itself, followed by two parameters:

Parameter 1: Number of 100 bytes rows to generate. In a real world cluster with high data capacity, you should use 10,000,000,000 , which is 1TB of data. But my cluster has only Four dataNodes and it’s capacity is lower than 1TB, So I used only 10737418 rows that makes up roughly 100Mb of data.

Parameter 2: Generated data will be dropped in the HDFS path you enter. The directory shouldn’t exist in advance and teragen will create it. If it already exist then teragen will throw an error.

This is the output. Similar to any MapReduce job:

[[email protected] ~]$ hadoop jar /opt/cloudera/parcels/CDH-5.12.0-1.cdh5.12.0.p0.29/lib/hadoop-mapreduce/hadoop-mapreduce-examples.jar teragen 10737418 /teragen
18/01/15 22:31:48 INFO client.RMProxy: Connecting to ResourceManager at cloudera1.lan/192.168.1.103:8032
18/01/15 22:31:51 INFO terasort.TeraGen: Generating 10737418 using 2
18/01/15 22:31:51 INFO mapreduce.JobSubmitter: number of splits:2
18/01/15 22:31:54 INFO mapreduce.JobSubmitter: Submitting tokens for job: job_1516047518405_0002
18/01/15 22:31:55 INFO impl.YarnClientImpl: Submitted application application_1516047518405_0002
18/01/15 22:31:55 INFO mapreduce.Job: The url to track the job: http://cloudera1.lan:8088/proxy/application_1516047518405_0002/
18/01/15 22:31:55 INFO mapreduce.Job: Running job: job_1516047518405_0002
18/01/15 22:32:07 INFO mapreduce.Job: Job job_1516047518405_0002 running in uber mode : false
18/01/15 22:32:07 INFO mapreduce.Job:  map 0% reduce 0%
18/01/15 22:32:27 INFO mapreduce.Job:  map 65% reduce 0%
18/01/15 22:32:31 INFO mapreduce.Job:  map 80% reduce 0%
18/01/15 22:32:33 INFO mapreduce.Job:  map 92% reduce 0%
18/01/15 22:32:39 INFO mapreduce.Job:  map 100% reduce 0%
18/01/15 22:32:42 INFO mapreduce.Job: Job job_1516047518405_0002 completed successfully
18/01/15 22:32:42 INFO mapreduce.Job: Counters: 31
        File System Counters
                FILE: Number of bytes read=0
                FILE: Number of bytes written=256130
                FILE: Number of read operations=0
                FILE: Number of large read operations=0
                FILE: Number of write operations=0
                HDFS: Number of bytes read=167
                HDFS: Number of bytes written=1073741800
                HDFS: Number of read operations=8
                HDFS: Number of large read operations=0
                HDFS: Number of write operations=4
        Job Counters
                Launched map tasks=2
                Other local map tasks=2
                Total time spent by all maps in occupied slots (ms)=54390
                Total time spent by all reduces in occupied slots (ms)=0
                Total time spent by all map tasks (ms)=54390
                Total vcore-milliseconds taken by all map tasks=54390
                Total megabyte-milliseconds taken by all map tasks=55695360
        Map-Reduce Framework
                Map input records=10737418
                Map output records=10737418
                Input split bytes=167
                Spilled Records=0
                Failed Shuffles=0
                Merged Map outputs=0
                GC time elapsed (ms)=380
                CPU time spent (ms)=24950
                Physical memory (bytes) snapshot=289558528
                Virtual memory (bytes) snapshot=5446606848
                Total committed heap usage (bytes)=255590400
        org.apache.hadoop.examples.terasort.TeraGen$Counters
                CHECKSUM=23055106908592388
        File Input Format Counters
                Bytes Read=0
        File Output Format Counters
                Bytes Written=1073741800

Now let’s look at the created files:

[[email protected] ~]$ hdfs dfs -ls /teragen
Found 3 items
-rw-r--r-- 2 hdfs supergroup 0 2018-01-15 22:32 /teragen/_SUCCESS
-rw-r--r-- 2 hdfs supergroup 536870900 2018-01-15 22:32 /teragen/part-m-00000
-rw-r--r-- 2 hdfs supergroup 536870900 2018-01-15 22:32 /teragen/part-m-00001

You can see that the program created Two files, each is a little above 50Mb.

TeraSort

The purpose of TeraSort is to test the CPU/Memory power of the cluster and to sort 1TB of data. The documentation for this command can be found here. As I mentioned above, I had to run it on a smaller, 100GB sample:

hadoop jar /opt/cloudera/parcels/CDH-5.12.0-1.cdh5.12.0.p0.29/lib/hadoop-mapreduce/hadoop-mapreduce-examples.jar terasort /teragen /terasort

It takes two parameters:

Parameter 1: The directory where the TeraGen files where created.

Parameter 2: a new directory where to create the output files of TeraSort. This directory must not exist in advance.

Here is the run log:

[[email protected] ~]$ hadoop jar /opt/cloudera/parcels/CDH-5.12.0-1.cdh5.12.0.p0.29/lib/hadoop-mapreduce/hadoop-mapreduce-examples.jar terasort /teragen /terasort
18/01/15 22:34:47 INFO terasort.TeraSort: starting
18/01/15 22:34:56 INFO input.FileInputFormat: Total input paths to process : 2
Spent 511ms computing base-splits.
Spent 17ms computing TeraScheduler splits.
Computing input splits took 531ms
Sampling 8 splits of 8
Making 1 from 100000 sampled records
Computing parititions took 3436ms
Spent 3974ms computing partitions.
18/01/15 22:35:00 INFO client.RMProxy: Connecting to ResourceManager at cloudera1.lan/192.168.1.103:8032
18/01/15 22:35:02 INFO mapreduce.JobSubmitter: number of splits:8
18/01/15 22:35:03 INFO mapreduce.JobSubmitter: Submitting tokens for job: job_1516047518405_0003
18/01/15 22:35:04 INFO impl.YarnClientImpl: Submitted application application_1516047518405_0003
18/01/15 22:35:05 INFO mapreduce.Job: The url to track the job: http://cloudera1.lan:8088/proxy/application_1516047518405_0003/
18/01/15 22:35:05 INFO mapreduce.Job: Running job: job_1516047518405_0003
18/01/15 22:35:18 INFO mapreduce.Job: Job job_1516047518405_0003 running in uber mode : false
18/01/15 22:35:18 INFO mapreduce.Job:  map 0% reduce 0%
18/01/15 22:35:36 INFO mapreduce.Job:  map 25% reduce 0%
18/01/15 22:35:53 INFO mapreduce.Job:  map 38% reduce 0%
18/01/15 22:35:54 INFO mapreduce.Job:  map 50% reduce 0%
18/01/15 22:36:12 INFO mapreduce.Job:  map 63% reduce 0%
18/01/15 22:36:13 INFO mapreduce.Job:  map 75% reduce 0%
18/01/15 22:36:28 INFO mapreduce.Job:  map 88% reduce 0%
18/01/15 22:36:30 INFO mapreduce.Job:  map 100% reduce 0%
18/01/15 22:36:49 INFO mapreduce.Job:  map 100% reduce 33%
18/01/15 22:36:56 INFO mapreduce.Job:  map 100% reduce 67%
18/01/15 22:37:02 INFO mapreduce.Job:  map 100% reduce 74%
18/01/15 22:37:08 INFO mapreduce.Job:  map 100% reduce 82%
18/01/15 22:37:14 INFO mapreduce.Job:  map 100% reduce 85%
18/01/15 22:37:20 INFO mapreduce.Job:  map 100% reduce 95%
18/01/15 22:37:24 INFO mapreduce.Job:  map 100% reduce 100%
18/01/15 22:37:24 INFO mapreduce.Job: Job job_1516047518405_0003 completed successfully
18/01/15 22:37:24 INFO mapreduce.Job: Counters: 50
        File System Counters
                FILE: Number of bytes read=475841697
                FILE: Number of bytes written=949567229
                FILE: Number of read operations=0
                FILE: Number of large read operations=0
                FILE: Number of write operations=0
                HDFS: Number of bytes read=1073742688
                HDFS: Number of bytes written=1073741800
                HDFS: Number of read operations=27
                HDFS: Number of large read operations=0
                HDFS: Number of write operations=2
        Job Counters
                Launched map tasks=8
                Launched reduce tasks=1
                Data-local map tasks=6
                Rack-local map tasks=2
                Total time spent by all maps in occupied slots (ms)=133888
                Total time spent by all reduces in occupied slots (ms)=51811
                Total time spent by all map tasks (ms)=133888
                Total time spent by all reduce tasks (ms)=51811
                Total vcore-milliseconds taken by all map tasks=133888
                Total vcore-milliseconds taken by all reduce tasks=51811
                Total megabyte-milliseconds taken by all map tasks=137101312
                Total megabyte-milliseconds taken by all reduce tasks=53054464
        Map-Reduce Framework
                Map input records=10737418
                Map output records=10737418
                Map output bytes=1095216636
                Map output materialized bytes=472560780
                Input split bytes=888
                Combine input records=0
                Combine output records=0
                Reduce input groups=10737418
                Reduce shuffle bytes=472560780
                Reduce input records=10737418
                Reduce output records=10737418
                Spilled Records=21474836
                Shuffled Maps =8
                Failed Shuffles=0
                Merged Map outputs=8
                GC time elapsed (ms)=2619
                CPU time spent (ms)=102910
                Physical memory (bytes) snapshot=4183957504
                Virtual memory (bytes) snapshot=24552275968
                Total committed heap usage (bytes)=4001071104
        Shuffle Errors
                BAD_ID=0
                CONNECTION=0
                IO_ERROR=0
                WRONG_LENGTH=0
                WRONG_MAP=0
                WRONG_REDUCE=0
        File Input Format Counters
                Bytes Read=1073741800
        File Output Format Counters
                Bytes Written=1073741800
18/01/15 22:37:24 INFO terasort.TeraSort: done

TeraValidate

This program acts on the output of teraSort and validates that the data is indeed sorted.

hadoop jar /opt/cloudera/parcels/CDH-5.12.0-1.cdh5.12.0.p0.29/lib/hadoop-mapreduce/hadoop-mapreduce-examples.jar teravalidate /terasort /teravalidate

18/01/15 23:30:45 INFO client.RMProxy: Connecting to ResourceManager at cloudera1.lan/192.168.1.103:8032
18/01/15 23:30:49 INFO input.FileInputFormat: Total input paths to process : 1
Spent 68ms computing base-splits.
Spent 6ms computing TeraScheduler splits.
18/01/15 23:30:49 INFO mapreduce.JobSubmitter: number of splits:1
18/01/15 23:30:51 INFO mapreduce.JobSubmitter: Submitting tokens for job: job_1515359398963_0001
18/01/15 23:30:54 INFO impl.YarnClientImpl: Submitted application application_1515359398963_0001
18/01/15 23:30:54 INFO mapreduce.Job: The url to track the job: http://cloudera1.lan:8088/proxy/application_1515359398963_0001/
18/01/15 23:30:54 INFO mapreduce.Job: Running job: job_1515359398963_0001
18/01/15 23:31:15 INFO mapreduce.Job: Job job_1515359398963_0001 running in uber mode : false
18/01/15 23:31:15 INFO mapreduce.Job: map 0% reduce 0%
18/01/15 23:31:40 INFO mapreduce.Job: map 32% reduce 0%
18/01/15 23:31:46 INFO mapreduce.Job: map 50% reduce 0%
18/01/15 23:31:51 INFO mapreduce.Job: map 100% reduce 0%
18/01/15 23:32:03 INFO mapreduce.Job: map 100% reduce 100%
18/01/157 23:32:03 INFO mapreduce.Job: Job job_1515359398963_0001 completed successfully
18/01/15 23:32:04 INFO mapreduce.Job: Counters: 49
 File System Counters
 FILE: Number of bytes read=100
 FILE: Number of bytes written=257037
 FILE: Number of read operations=0
 FILE: Number of large read operations=0
 FILE: Number of write operations=0
 HDFS: Number of bytes read=1073741912
 HDFS: Number of bytes written=24
 HDFS: Number of read operations=6
 HDFS: Number of large read operations=0
 HDFS: Number of write operations=2
 Job Counters
 Launched map tasks=1
 Launched reduce tasks=1
 Data-local map tasks=1
 Total time spent by all maps in occupied slots (ms)=33303
 Total time spent by all reduces in occupied slots (ms)=9095
 Total time spent by all map tasks (ms)=33303
 Total time spent by all reduce tasks (ms)=9095
 Total vcore-milliseconds taken by all map tasks=33303
 Total vcore-milliseconds taken by all reduce tasks=9095
 Total megabyte-milliseconds taken by all map tasks=34102272
 Total megabyte-milliseconds taken by all reduce tasks=9313280
 Map-Reduce Framework
 Map input records=10737418
 Map output records=3
 Map output bytes=82
 Map output materialized bytes=96
 Input split bytes=112
 Combine input records=0
 Combine output records=0
 Reduce input groups=3
 Reduce shuffle bytes=96
 Reduce input records=3
 Reduce output records=1
 Spilled Records=6
 Shuffled Maps =1
 Failed Shuffles=0
 Merged Map outputs=1
 GC time elapsed (ms)=312
 CPU time spent (ms)=17820
 Physical memory (bytes) snapshot=553263104
 Virtual memory (bytes) snapshot=5466845184
 Total committed heap usage (bytes)=524029952
 Shuffle Errors
 BAD_ID=0
 CONNECTION=0
 IO_ERROR=0
 WRONG_LENGTH=0
 WRONG_MAP=0
 WRONG_REDUCE=0
 File Input Format Counters
 Bytes Read=1073741800
 File Output Format Counters
 Bytes Written=24

If we look at the output directory, we will see that the validation result is success and no report was generated (report is generated only if problems are found):

[[email protected] ~]$ hdfs dfs -ls /teravalidate
Found 2 items
-rw-r--r-- 2 hdfs supergroup 0 2018-01-07 23:32 /teravalidate/_SUCCESS
-rw-r--r-- 2 hdfs supergroup 24 2018-01-07 23:32 /teravalidate/part-r-00000

Now you can examine the time that took each utility to run and compare it to the time it took on other clusters or with different setups (on my cluster it took only  about a minute because the dataset was small, but if you run it on real terabyte of data it takes longer). Here is a screenshot from the YARN UI where you can see the timing of each run:

view full size image

An example use case can be comparing a cluster’s performance when using SSD drives to the same cluster’s performance when using magnetic HDD drives:

(The chart is just a demo, it’s not based on real tests I made).

This ends the part of the Tera* trio. Next time we will see another trio that tests specific parts of Hadoop: Namenode, MapReduce and IO performance.

 

This entry was posted in Cloudera, Hadoop and tagged , , , , , . Bookmark the permalink.

Leave a Reply