Higher GET latencies with --treescan

[jayrajput0]

Looks like I am not allowed to reopen the Issue therefore creating a new one with reference to it

hi @jayrajput0 ,
you might just want to use the "--treescan" option for the read/delete. this way, you can delete whatever number of objects you see fit in a time-limited write phase, for example like this to start creating a total of 6400 16MB-sized objects via 64 threads and stop after 4 seconds:

elbencho -s 16m -b 16m -t 64 -w mybucket --s3objprefix testprefix1/ -N 100 --timelimit 4 --s3endpoints ...

now for the reads we don't know if all the files have been created or not. for this, we can use the "--treescan" option. it will discover all the objects under a given path and then apply the given operation (e.g. read or delete) to the objects under the given bucket and s3 object prefix. in our example, the treescan bucket/prefix will be the same as the given bucket/prefix where we want to apply the operation.
so for timelimited reads it could look like this:

elbencho -s 16m -b 16m -t 64 -r mybucket --s3objprefix testprefix1/ --timelimit 4 --treescan s3://mybucket/testprefix1/ --s3endpoints ...

and for deletes you can use a command line simiar to the reads with the "--treescan", with or without timelimit, depending on whether you want to be sure that all objects get deleted in the end or not.

i'm closing this issue in the hope that this solution works for you. if not then of course please feel free to re-open this issue.

Originally posted by @breuner in #80

================================

Hello Sven,
Hope you are doing well!
Sorry I couldn't validate the suggested --treescan option last time due to time constraints.

Here is my GOAL:
I want to run a time bound PUT (write) test and it's really difficult to forecast the object count therefore I pass a very high object count along with --timelimit .

Issue:
The problem with above method is that GET starts failing with error Object download failed.

Suggested solution:
As you suggested to use --treescan, I tested the same but the latencies reported with --treescan is higher therefore it defeats the purpose.

I performed below Tests:

TEST SCENARIO 01:

1. Uploading objects with timelimit 300sec and very high object count 99999999999 to make sure that test runs for 5 mins.

# elbencho --hosts xxxx --numhosts 3 --s3endpoints xxxxxxxx --s3key xxx--s3secret xxxxx-w -s 64k -b 64k -t 8 -n 3 -N 99999999999 --nolive --lat --latpercent --latpercent9s 0 --direct --s3nompcheck --s3objprefix X5D  --timelimit 300 --csvfile=put-3h.csv --resfile=put-3h.out --port 13001 01test1
OPERATION   RESULT TYPE         FIRST DONE   LAST DONE
=========== ================    ==========   =========
WRITE       Elapsed time     :    5m0.249s    5m0.254s
            Objects/s        :        5532        5538
            Throughput MiB/s :         345         346
            Total MiB        :      103812      103929
            Objects total    :     1660997     1662856
            Objects latency  : [ min=3.34ms avg=4.33ms max=1.25s ]
            Objects lat % us : [ 1%<=4096 50%<=4096 75%<=4871 99%<=6889 ]
            IO latency       : [ min=3.34ms avg=4.33ms max=1.25s ]
            IO lat % us      : [ 1%<=4096 50%<=4096 75%<=4871 99%<=6889 ]

Terminating due to phase time limit.

2: Running GET(read) on the same bucket with --treescan

# elbencho --hosts xxxxx --numhosts 3 --s3endpoints $ebEndpoints --s3key xxx--s3secret xxxx-r -s 64k -b 64k -t 8 -n 3 -N 99999999999 --nolive --lat --latpercent --latpercent9s 0 --direct --s3nompcheck --s3ignoreerrors --s3objprefix X5D --treescan s3://01test1/ --timelimit 300 --csvfile=get-ignore-scan.csv --resfile=get-ignore-scan.out --port 13001 01test1
NOTE: Bucket scan finished. Objects: 1662879; Elapsed: 28s  <----------
OPERATION   RESULT TYPE         FIRST DONE   LAST DONE
=========== ================    ==========   =========
READ        Elapsed time     :   4m32.451s    5m0.346s
            Objects/s        :        4625        4286
            Objects total    :     1260235     1287520
            Objects latency  : [ min=672us avg=5.48ms max=12.9s ]
            Objects lat % us : [ 1%<=861 50%<=1722 75%<=2435 99%<=110218 ]
            IO latency       : [ min=670us avg=5.48ms max=12.9s ]                                        <<<<<<<<<<<<<<<<See latencies
            IO lat % us      : [ 1%<=861 50%<=1722 75%<=2435 99%<=110218 ]

Terminating due to phase time limit.

TEST SCENARIO 02

1. Uploading a fixed no of objects without timelimit to make sure all write operations succeeds. (choose the same no of objects as written in first test. )

# elbencho --hosts  xxx--numhosts 3 --s3endpoints xxxxx --s3key xxx--s3secret xxx-w -s 64k -b 64k -t 8 -n 3 -N 23095 --nolive --lat --latpercent --latpercent9s 0 --direct --s3nompcheck --s3objprefix X5D --csvfile=put-3h-objs.csv --resfile=put-3h_objs.out --port 13001 01test3
OPERATION   RESULT TYPE         FIRST DONE   LAST DONE
=========== ================    ==========   =========
WRITE       Elapsed time     :   4m47.980s   6m15.650s                
            Objects/s        :        5501        4426
            Throughput MiB/s :         343         276
            Total MiB        :       99011      103927
            Objects total    :     1584181     1662840
            Objects latency  : [ min=3.30ms avg=4.38ms max=239ms ]
            Objects lat % us : [ 1%<=4096 50%<=4096 75%<=4871 99%<=6889 ]
            IO latency       : [ min=3.30ms avg=4.38ms max=239ms ]
            IO lat % us      : [ 1%<=4096 50%<=4096 75%<=4871 99%<=6889 ]

2. GET( read) without --treescan

# elbencho --hosts 10.64.8.122,10.64.8.123,10.64.8.124 --numhosts 3 --s3endpoints $ebEndpoints --s3key access --s3secret secret -r -s 64k -b 64k -t 8 -n 3 -N 23095 --nolive --lat --latpercent --latpercent9s 0 --direct --s3nompcheck --s3objprefix X5D --timelimit 300 --csvfile=get.csv --resfile=get.out --port 13001 01test3
OPERATION   RESULT TYPE         FIRST DONE   LAST DONE
=========== ================    ==========   =========
READ        Elapsed time     :   2m15.073s   2m15.634s
            Objects/s        :       12281       12259
            Throughput MiB/s :         767         766
            Total MiB        :      103682      103927
            Objects total    :     1658927     1662840
            Objects latency  : [ min=1.33ms avg=1.95ms max=8.45ms ]
            Objects lat % us : [ 1%<=1722 50%<=2048 75%<=2048 99%<=2435 ]
            IO latency       : [ min=1.33ms avg=1.95ms max=8.45ms ]                                <<<<<<<<<<<<<<<<<<Lower latencies.
            IO lat % us      : [ 1%<=1722 50%<=2048 75%<=2048 99%<=2435 ]

Queries

• Do we have any mechanism to run a timebound PUT and GET test without worrying about forecasting the object counts because that's really tedious(up to some extent impractical) job to do even before we benchmark a system.
• If the --treescan is an option then it shouldn't affect the latencies, is there any other possibilities ?

[jayrajput0]

Tested one more scenario:
Executed another test with --treescan but dropped the --s3ignoreerrors, to my surprise it brought down the latencies and it was able to complete the read operation within 2 ms.
DO you think --s3ignoreerrors is the real culprit behind higher latency?

• read with --treescan, and without --s3ignoreerrors

# elbencho --hosts  xxxx--numhosts 3 --s3endpoints $ebEndpoints --s3key xxx--s3secret xxx-r -s 64k -b 64k -t 8 -n 3 -N 99999999999 --nolive --lat --latpercent --latpercent9s 0 --direct --s3nompcheck --treescan s3://01test1/ --timelimit 300 --csvfile=get-noignore-scan.csv --resfile=get-noignore-scan.out --port 13001 01test1
NOTE: Bucket scan finished. Objects: 1662879; Elapsed: 28s
OPERATION   RESULT TYPE         FIRST DONE   LAST DONE
=========== ================    ==========   =========
READ        Elapsed time     :   2m18.066s   2m18.732s         <<<<<<<<<<<<<<   
            Objects/s        :       12024       11986
            Throughput MiB/s :         751         749
            Total MiB        :      103762      103929
            Objects total    :     1660199     1662879
            Objects latency  : [ min=1.50ms avg=2.00ms max=35.9ms ]
            Objects lat % us : [ 1%<=1722 50%<=2048 75%<=2435 99%<=2435 ]
            IO latency       : [ min=1.49ms avg=2.00ms max=35.9ms ]   <<<<<<<<<<<<<<See latencies
            IO lat % us      : [ 1%<=1722 50%<=2048 75%<=2435 99%<=2435 ]

[breuner]

hi @jayrajput0 , thanks for reaching out again.

this is very surprising to me, because i don't see any general reason why the Gets with --treescan would be slower than the Gets without the treescan option, because all the extra scanning work that the --treescan option has happens in the beginning during those 28sec in your example, before the actual Gets start.

the --s3ignoreerrors option ignores problems that would otherwise make elbencho exit with an error. dropping it cannot have any positive influence on the performance number unless you have a case where actual errors are happening on the server. to give an example: if you were trying to read objects that don't exist in the bucket then that would be an error in this sense. if you would have the --s3ignoreerrors option then elbencho would continue to run despite such an otherwise fatal error and thus might report an unusually high number of objects per second (because reading non-existing objects that can't actually be read is faster than reading actually existing objects), but i don't think this applies to your case.

in other words: from the datapoints that we have so far, my guess would be that there is other variance in the system that explains the performance difference in your test cases, because otherwise there would be no reason why dropping the --s3ignoreerrors option made any difference.

is the object store always otherwise idle when you are testing it or are there possibly other workloads running while you're running your performance tests on the system?

[jayrajput0]

There are no other workloads running, neither the backend storage cluster nor the client machines are shared with any other workload. it's my new setup which I am going to benchmark.

[breuner]

hi @jayrajput0 ,
i ran a test to confirm that there is no general difference in speed between reading with and without treescan, within normal variance between test runs:

i created a dataset with over 1.4M files like this:

[breuner@node001 ~]$ elbencho --s3endpoints "http://172.200.210.[1-12]" -w -r -b 64k -s 64k -t 16 -n 1 -N 10000 --lat --s3objprefix for-janmejay1 sven-bucket --hosts 10.143.14."[91,95,101,103,107,111,113,115,117]" 
OPERATION   RESULT TYPE         FIRST DONE   LAST DONE
=========== ================    ==========   =========
WRITE       Elapsed time     :     30.361s     31.985s
            Objects/s        :       45939       45021
            Throughput MiB/s :        2871        2813
            Total MiB        :       87181       90000
            Objects total    :     1394778     1440000
            Objects latency  : [ min=1.58ms avg=3.12ms max=50.7ms ]
            IO latency       : [ min=1.58ms avg=3.12ms max=50.7ms ]
---

then i read it first without treescan:

[breuner@node001 ~]$ elbencho --s3endpoints "http://172.200.210.[1-12]" -r -b 64k -s 64k -t 16 -n 1 -N 10000 --lat --s3objprefix for-janmejay1/ sven-bucket --hosts 10.143.14."[91,95,101,103,107,111,113,115,117]" 
OPERATION   RESULT TYPE         FIRST DONE   LAST DONE
=========== ================    ==========   =========
READ        Elapsed time     :     19.815s     20.675s
            Objects/s        :       71606       69646
            Throughput MiB/s :        4475        4352
            Total MiB        :       88682       90000
            Objects total    :     1418913     1440000
            Objects latency  : [ min=898us avg=2.00ms max=8.00ms ]
            IO latency       : [ min=896us avg=2.00ms max=8.00ms ]
---

and again with treescan, giving us the same result within normal variance:

[breuner@node001 ~]$ elbencho --s3endpoints "http://172.200.210.[1-12]" -r -b 64k -s 64k -t 16 --treescan s3://sven-bucket/fon-janmejay1/ --lat --s3objprefix for-janmejay1/ sven-bucket --hosts 10.143.14."[91,95,101,103,107,111,113,115,117]" 
NOTE: Bucket scan finished. Objects: 1440000; Elapsed: 21s
OPERATION   RESULT TYPE         FIRST DONE   LAST DONE
=========== ================    ==========   =========
READ        Elapsed time     :     19.788s     20.681s
            Objects/s        :       71281       69629
            Throughput MiB/s :        4455        4351
            Total MiB        :       88160       90000
            Objects total    :     1410558     1440000
            Objects latency  : [ min=884us avg=2.02ms max=9.48ms ]
            IO latency       : [ min=882us avg=2.02ms max=9.48ms ]
---

and just to be extra sure, here's also a run with "--treescan" and additional "--s3ignoreerrors", which has again the same result within normal variance:

[breuner@node001 ~]$ elbencho --s3endpoints "http://172.200.210.[1-12]" -r -b 64k -s 64k -t 16 --treescan s3://sven-bucket/fon-janmejay1/ --lat --s3objprefix fon-janmejay1/ sven-bucket --hosts 10.143.14."[91,95,101,103,107,111,113,115,117]" --s3ignoreerrors
NOTE: Bucket scan finished. Objects: 1440000; Elapsed: 18s
OPERATION   RESULT TYPE         FIRST DONE   LAST DONE
=========== ================    ==========   =========
READ        Elapsed time     :     19.731s     20.310s
            Objects/s        :       71321       70897
            Throughput MiB/s :        4457        4431
            Total MiB        :       87956       90000
            Objects total    :     1407297     1440000
            Objects latency  : [ min=889us avg=2.00ms max=6.01ms ]
            IO latency       : [ min=888us avg=2.00ms max=6.00ms ]
---

Did you maybe find any errors in the server logs during the tests that would explain the difference that you observed?

There's also the "--s3log" parameter in elbencho that can enable the logging of the AWS SDK CPP, but this might produce too much output to be useful in this context.

By the way: I've also sent a reply to your other issue here: #83 (comment) . This is most likely unrelated to the issue here, I'm just mentioning it here because I wasn't sure if you get a notification for a reply to a closed issue.

[jayrajput0]

Hello Sven,
I executed the test multiple time and the results were bit inconsistent,there were no other workloads running. However, I am continuing with treescan as last couple of tests showed me consitent results, I am monitoring the latencies and will keep you posted with my observations.
And yes, I got notified for the closed issue as well.

[breuner]

Hi @jayrajput0 , should we keep this issue open or can we close it?