Log iteration to result count in BulkImport code

[DomGarguilo]

Related to #5201. Logs the number of iterations performed to produce the resulting returned value (overlapping tablets). This will make it more evident if this code is doing a lot of scanning relative to the number of values we are looking for.

[DomGarguilo]

I am still looking into things to see if...

• a test can be added that might point out the bug that is outlined in Bulk import times scale with the number of tablets in a table. #5201
• a message should only be logged if the ratio of iterations to resulting tablets reaches a certain ratio. For example if we perform 100 iterations to only produce 20 tablets we should log but if the ratio is closer to 1:1 there may be no reason to log

Input on either of these would be helpful.

[keith-turner]

I believe this code is ok, it jump around in the metadata table and does not scan over tablets it does not need to.

The code that does scan over unrelated tablets in the metadata table is here . Would be good to track counts of skipped vs total tablets in that code. The function is called multiple times for a single bulk load and could get the counts from all calls and log after that loop that calls the function.

[DomGarguilo]

Good catch. I moved the log message to the spot you mentioned.

I added a check so things are only logged if there are "wasted iterations". With that check in place I can't get the message to be logged.

[keith-turner]

I added a check so things are only logged if there are "wasted iterations". With that check in place I can't get the message to be logged.

Which test are you running? The code seems ok, but it would be good to see the log message.

[DomGarguilo]

I was running BulkNewIT

[ddanielr]

Created #5345 without seeing these changes.

I think your changes are better as these directly show the time wasted skipping.

[DomGarguilo]

The updating logging as of 03de2e4 looks like this:

INFO : Bulk import stats for file:/home/dgarguilo/github/accumulo/test/target/mini-tests/org.apache.accumulo.test.functional.BulkNewIT_SharedMiniClusterBase/tmp/testBulkFile-BulkNewIT_testLoadPlan0 (tid = FATE[7d22613fda84ceda]): processed 6 tablets in 5 calls which took 25ms (25917117 nanos). Skipped 13 iterations which took 2ms (2606088 nanos) or 10% of the time.

I added the changes in commit 2ebdd00 and ran BulkNewIT to get the log above

[ddanielr]

I like the new changes.