Measure upload/download bandwidth; support different read policies, and optionally save the output to a CSV file.
> hadoop jar cloudstore-1.6.jar bandwidth
Usage: bandwidth [options] size <path>
-D <key=value> Define a single configuration option
-sysprop <file> Property file of system properties
-tokenfile <file> Hadoop token file to load
-xmlfile <file> XML config file to load
-verbose verbose output
-debug enable JVM logs (ALL) and override log4j levels (DEBUG) on specified packages or classes
-logoverrides <file> A newline separated list of package and class names
-block <size> block size in megabytes
-csv <file> CSV file to log operation details
-flush flush the output after writing each block
-hflush hflush() the output after writing each block
-keep do not delete the file
-rename rename file to suffix .renamed
-policy <policy> read policy for file (whole-file, sequential, random...). use "none" to use whatever is set for the store
Upload 128M of data to s3 with a block size of 8 megabytes; use -verbose output to print stream and filesystem statistics. Save the summary to a CSV file for review.
> hadoop jar cloudstore-1.6.jar bandwidth -csv tmp/s3a128m.csv -block 8 -verbose -policy whole-file 128m s3a://example-london/tmp
Bandwidth test against s3a://example-london/tmp with data size 128m
==================================================================
Block size 8 MB
Saving statistics as CSV data to tmp/s3a128m.csv
2023-09-14 13:57:00,959 [main] INFO impl.DirectoryPolicyImpl (DirectoryPolicyImpl.java:getDirectoryPolicy(189)) - Directory markers will be kept
Using filesystem s3a://example-london
Upload size in Megabytes 128 MB
Writing data as 16 blocks each of size 8,388,608 bytes
Starting: Opening s3a://example-london/tmp for upload
Duration of Opening s3a://example-london/tmp for upload: 0:00.397
Write block 0 in 0.002 seconds
Write block 1 in 0.002 seconds
Write block 2 in 0.002 seconds
Write block 3 in 0.099 seconds
Write block 4 in 0.002 seconds
Write block 5 in 0.002 seconds
Write block 6 in 0.003 seconds
Write block 7 in 0.002 seconds
Write block 8 in 0.002 seconds
Write block 9 in 0.002 seconds
Write block 10 in 0.002 seconds
Write block 11 in 11.093 seconds
Write block 12 in 0.004 seconds
Write block 13 in 0.003 seconds
Write block 14 in 0.002 seconds
Write block 15 in 8.248 seconds
Starting: upload stream close()
Duration of upload stream close(): 0:11.706
Progress callbacks 16420; in close 5734
Upload Stream: FSDataOutputStream{wrappedStream=S3ABlockOutputStream{WriteOperationHelper {bucket=example-london}, blockSize=33554432 Statistics=counters=((stream_write_bytes=134217728) (multipart_upload_completed.failures=0) (op_hsync=0) (multipart_upload_completed=1) (stream_write_exceptions=0) (stream_write_block_uploads=4) (stream_write_queue_duration=0) (op_hflush=0) (action_executor_acquired.failures=0) (stream_write_total_time=0) (stream_write_exceptions_completing_upload=0) (action_executor_acquired=0) (op_abort.failures=0) (op_abort=0) (object_multipart_aborted.failures=0) (stream_write_total_data=134217728) (object_multipart_aborted=0));
gauges=((stream_write_block_uploads_pending=0) (stream_write_block_uploads_data_pending=0));
minimums=((action_executor_acquired.failures.min=-1) (multipart_upload_completed.min=119) (object_multipart_aborted.failures.min=-1) (op_abort.min=-1) (action_executor_acquired.min=1) (object_multipart_aborted.min=-1) (multipart_upload_completed.failures.min=-1) (op_abort.failures.min=-1));
maximums=((action_executor_acquired.max=11092) (object_multipart_aborted.failures.max=-1) (op_abort.max=-1) (object_multipart_aborted.max=-1) (multipart_upload_completed.failures.max=-1) (op_abort.failures.max=-1) (action_executor_acquired.failures.max=-1) (multipart_upload_completed.max=119));
means=((object_multipart_aborted.mean=(samples=0, sum=0, mean=0.0000)) (op_abort.failures.mean=(samples=0, sum=0, mean=0.0000)) (action_executor_acquired.mean=(samples=4, sum=19349, mean=4837.2500)) (op_abort.mean=(samples=0, sum=0, mean=0.0000)) (action_executor_acquired.failures.mean=(samples=0, sum=0, mean=0.0000)) (multipart_upload_completed.failures.mean=(samples=0, sum=0, mean=0.0000)) (multipart_upload_completed.mean=(samples=1, sum=119, mean=119.0000)) (object_multipart_aborted.failures.mean=(samples=0, sum=0, mean=0.0000)));
}}
FileSystem s3a://example-london
S3AFileSystem{uri=s3a://example-london, workingDir=s3a://example-london/user/alice, inputPolicy=normal, partSize=33554432, enableMultiObjectsDelete=true, maxKeys=5000, readAhead=32768, blockSize=33554432, multiPartThreshold=134217728, s3EncryptionAlgorithm='SSE_KMS', blockFactory=org.apache.hadoop.fs.s3a.S3ADataBlocks$DiskBlockFactory@a7f0ab6, auditManager=Service ActiveAuditManagerS3A in state ActiveAuditManagerS3A: STARTED, auditor=LoggingAuditor{ID='ee1422f2-dd3f-489a-a9a3-fb5fee3db23e', headerEnabled=true, rejectOutOfSpan=false}}, authoritativePath=[], useListV1=false, magicCommitter=true, boundedExecutor=BlockingThreadPoolExecutorService{SemaphoredDelegatingExecutor{permitCount=384, available=384, waiting=0}, activeCount=0}, unboundedExecutor=java.util.concurrent.ThreadPoolExecutor@41f35f7c[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0], credentials=AWSCredentialProviderList[refcount= 1: [TemporaryAWSCredentialsProvider, SimpleAWSCredentialsProvider] last provider: SimpleAWSCredentialsProvider, delegation tokens=disabled, DirectoryMarkerRetention{policy='keep'}, instrumentation {S3AInstrumentation{}}, ClientSideEncryption=false}
Download s3a://example-london/tmp
================================
Starting: open s3a://example-london/tmp
Read block 0 in 1.773 seconds
Read block 1 in 3.491 seconds
Read block 2 in 4.255 seconds
Read block 3 in 4.929 seconds
Read block 4 in 5.030 seconds
Read block 5 in 4.648 seconds
Read block 6 in 3.951 seconds
Read block 7 in 5.080 seconds
Read block 8 in 3.548 seconds
Read block 9 in 5.085 seconds
Read block 10 in 4.298 seconds
Read block 11 in 3.824 seconds
Read block 12 in 3.883 seconds
Read block 13 in 5.594 seconds
Read block 14 in 5.318 seconds
Read block 15 in 4.743 seconds
Starting: download stream close()
Duration of download stream close(): 0:00.003
Download Stream: org.apache.hadoop.fs.FSDataInputStream@4784013e: S3AInputStream{s3a://example-london/tmp wrappedStream=closed read policy=normal pos=134217728 nextReadPos=0 contentLength=134217728 contentRangeStart=0 contentRangeFinish=134217728 remainingInCurrentRequest=0 ChangeTracker{VersionIdChangeDetectionPolicy mode=Server, revisionId='_p9gzHB4V256F6gROEMs5dP8MQqFGvik'}
StreamStatistics{counters=((stream_read_fully_operations=16) (stream_read_seek_backward_operations=0) (stream_read_seek_policy_changed=1) (stream_read_seek_operations=0) (stream_read_seek_bytes_skipped=0) (action_http_get_request=1) (stream_read_total_bytes=134217728) (stream_read_bytes=134217728) (stream_read_version_mismatches=0) (stream_read_unbuffered=0) (stream_read_opened=1) (stream_read_closed=1) (stream_read_exceptions=0) (stream_read_close_operations=1) (stream_read_seek_forward_operations=0) (stream_read_seek_bytes_discarded=0) (stream_read_bytes_discarded_in_abort=0) (stream_read_operations=8323) (stream_read_bytes_backwards_on_seek=0) (stream_read_bytes_discarded_in_close=0) (stream_read_operations_incomplete=8307) (stream_aborted=0) (action_http_get_request.failures=0));
gauges=((stream_read_gauge_input_policy=0));
minimums=((action_http_get_request.min=62) (action_http_get_request.failures.min=-1));
maximums=((action_http_get_request.failures.max=-1) (action_http_get_request.max=62));
means=((action_http_get_request.failures.mean=(samples=0, sum=0, mean=0.0000)) (action_http_get_request.mean=(samples=1, sum=62, mean=62.0000)));
}}
Starting: delete file s3a://example-london/tmp
Duration of delete file s3a://example-london/tmp: 0:00.161
Upload Summary
==============
Data size 134,217,728 bytes
Upload duration 0:31.598
Upload bandwidth in Megabits/second 32.407 Mbit/s
Upload bandwidth in Megabytes/second 4.051 MB/s
Blocks uploaded (ignoring close() overhead): 16: min 0.002 seconds, max 11.093 seconds, mean 1.217 seconds,
Close() duration: 0:11.706 (minute:seconds)
Mean Upload duration/block including close() overhead 3.191 seconds
Download Summary
================
Data size 134,217,728 bytes
Download duration 1:09.531
Download bandwidth in Megabits/second 14.727 Mbit/s
Download bandwidth in Megabytes/second 1.841 MB/s
Blocks downloaded: 16: min 1.773 seconds, max 5.594 seconds, mean 4.341 seconds,
CSV formatted data saved to tmp/s3a128m.csv
This example was executed on hadoop 3.3.4 against a remote AWS S3 store.
Note how most of the upload happened in the close() call. This is typical when the data being written is generated faster than the upload bandwidth of the uplink; the close() call blocks until the upload is complete.
This is also why application code which assumes that closing a stream is fast is at risk of problems when this happens, such as timing out if heartbeats are required to be generated during the upload.
The CSV file records the operations which have taken place, bytes processed and duration.
| Column | Meaning |
|---|---|
| operation | operation which took place |
| bytes | bytes processed in operation |
| total bytes | total bytes in ongoing sequence |
| duration/millis | duration in milliseconds |
| Operation | Meaning |
|---|---|
| create-file | file creation |
| upload-block | upload an individual block |
| close-upload | close() the output stream to complete the upload |
| upload | total upload time |
| open-for-download | open the file for download |
| download-block | download an individual block |
| download | total download time |
Here is the CSV output from the previous example.
Note how the upload operations initially take on a few milliseconds, but there are some which take seconds.
This operation is to the AWS S3 store, where writes are done in blocks; the 99 mS delay on block four is probably the multipart upload being initiated and the first block being asynchronously queued for upload. The threshold is set in fs.s3a.multipart.size
<property> <name>fs.s3a.fast.upload.active.blocks</name> <value>2</value> </property> <property> <name>fs.s3a.multipart.size</name> <value>32M</value> </property>
The next big delays of 110993 and 8248 ms are due not to blocks being uploaded, but in waiting for the block queue to have space to queue another asynchronous block upload -that is, to wait for an ongoing upload to complete.
The close-upload operation is when the upload completes and all buffers being written to are complete, then the final multipart operation is finished.
On S3A, for data below the multipart threshold, all the upload takes place in the close() call. (Excluding the “magic” uploads of the magic s3a committer; these are always multipart writes.)
The download bandwidth in this experiment (Macbook Pro M1; WiFi) is less than the upload. This is because a single HTTP stream is being used for download; there is no parallelism and the application has to wait for data to be streamed in.
There are two ways in some recent Hadoop releases to speed this up.
"operation","bytes","total","duration" "create-file",0,0,397 "upload-block",8388608,8388608,2 "upload-block",8388608,16777216,2 "upload-block",8388608,25165824,2 "upload-block",8388608,33554432,99 "upload-block",8388608,41943040,2 "upload-block",8388608,50331648,2 "upload-block",8388608,58720256,3 "upload-block",8388608,67108864,2 "upload-block",8388608,75497472,2 "upload-block",8388608,83886080,2 "upload-block",8388608,92274688,2 "upload-block",8388608,100663296,11093 "upload-block",8388608,109051904,4 "upload-block",8388608,117440512,3 "upload-block",8388608,125829120,2 "upload-block",8388608,134217728,8248 "close-upload",0,134217728,11706 "upload",8388608,8388608,31598 "open-for-download",0,0,47 "download-block",8388608,8388608,1773 "download-block",8388608,16777216,3491 "download-block",8388608,25165824,4255 "download-block",8388608,33554432,4929 "download-block",8388608,41943040,5030 "download-block",8388608,50331648,4648 "download-block",8388608,58720256,3951 "download-block",8388608,67108864,5080 "download-block",8388608,75497472,3548 "download-block",8388608,83886080,5085 "download-block",8388608,92274688,4298 "download-block",8388608,100663296,3824 "download-block",8388608,109051904,3883 "download-block",8388608,117440512,5594 "download-block",8388608,125829120,5318 "download-block",8388608,134217728,4743 "download",134217728,134217728,69531
Here's the experiment repeated with prefetching enabled and changes to block upload policy
<property> <name>fs.s3a.fast.upload.active.blocks</name> <value>4</value> </property> <property> <name>fs.s3a.multipart.size</name> <value>24M</value> </property>
bin/hadoop jar cloudstore-1.6.jar bandwidth -D fs.s3a.prefetch.enabled=true -csv tmp/s3a128mp.csv -block 8 -verbose -policy whole-file 128m s3a://example-london Upload Summary ============== Data size 134,217,728 bytes Upload duration 1:19.081 Upload bandwidth in Megabits/second 12.949 Mbit/s Upload bandwidth in Megabytes/second 1.619 MB/s Blocks uploaded (ignoring close() overhead): 16: min 0.000 seconds, max 49.304 seconds, mean 3.092 seconds, Close() duration: 0:29.135 (minute:seconds) Mean Upload duration/block including close() overhead 8.034 seconds Download Summary ================ Data size 134,217,728 bytes Download duration 0:29.669 Download bandwidth in Megabits/second 34.514 Mbit/s Download bandwidth in Megabytes/second 4.314 MB/s Blocks downloaded: 16: min 0.001 seconds, max 11.143 seconds, mean 1.851 seconds,
The changed upload settings: smaller blocks and a bigger queue actually seemed to slow down the upload performance.
Possible causes
Download time was significantly faster, more than doubling its bandwidth.
"operation","bytes","total","duration" "create-file",0,0,453 "upload-block",8388608,8388608,0 "upload-block",8388608,16777216,1 "upload-block",8388608,25165824,148 "upload-block",8388608,33554432,3 "upload-block",8388608,41943040,0 "upload-block",8388608,50331648,1 "upload-block",8388608,58720256,4 "upload-block",8388608,67108864,1 "upload-block",8388608,75497472,0 "upload-block",8388608,83886080,4 "upload-block",8388608,92274688,1 "upload-block",8388608,100663296,0 "upload-block",8388608,109051904,3 "upload-block",8388608,117440512,1 "upload-block",8388608,125829120,49304 "upload-block",8388608,134217728,1 "close-upload",0,134217728,29135 "upload",8388608,8388608,79081
The CSV file implies that most blocks were written straight to disk cache; one block write blocked for 49 seconds waiting for more capacity.
"open-for-download",0,0,22 "download-block",8388608,8388608,1862 "download-block",8388608,16777216,11143 "download-block",8388608,25165824,588 "download-block",8388608,33554432,502 "download-block",8388608,41943040,3443 "download-block",8388608,50331648,1 "download-block",8388608,58720256,1 "download-block",8388608,67108864,1 "download-block",8388608,75497472,1 "download-block",8388608,83886080,1848 "download-block",8388608,92274688,2380 "download-block",8388608,100663296,1 "download-block",8388608,109051904,6393 "download-block",8388608,117440512,1 "download-block",8388608,125829120,1 "download-block",8388608,134217728,1457 "download",134217728,134217728,29669
Download performance shows a slow read for the first blocks, but then subsequent reads are either very fast (data already downloaded and cached to disk), or a read needs to complete.
Again, more experiments would be needed to reach conclusions here.