Best way to get accurate time of execution for apex code?

Question

I'm trying to do performance tuning on some code I'm working on.

I'm currently checking the total execution time with this process:

Datetime startTime = Datetime.now();
/* run some code here */
Datetime endTime = Datetime.now();
System.debug('final time: ' + (endTime.getTime() - startTime.getTime());

My issue is that I get widely different times when I run the code. The first time I run it is always the longest. The second time the time gets way shorter, like almost 50% faster. Subsequent runs usually make a little improvement too. I'm guessing there's some sort of caching or optimization for code that is recently run that's making these improvements, but it becomes very difficult to tell if the changes I'm making are actually improving the efficiency or not. There's no chance that the amount of data processed is different for different runs.

Is there a better way to be testing cpu time usage?

Answer 1

First of all, remember that Salesforce is a shared resource. One second it might be idle, the next second it might be heavily loaded. There's generally no way to know the exact state when you start. Secondly, remember that these methods are only accurate to the nearest millisecond, so your testing must be meaningfully longer than 1 millisecond, and bigger is better.

Because of the first point, I always make it a point to run all methods in the same transaction. This will give a more consistent 1:1 ratio of code execution. Due to the second point, I always try to aim for 10,000ms of CPU usage. Use a binary search if you want to finetune your results.

For example, I'll start with 100,000 iterations. If that's too much, I go down to 50,000, then either 25,000 or 75,000, etc. If it's too little, I would go up to 200,000, then either 150,000 or 400,000, etc. Eventually, you'll find a way to maximize your CPU time.

The goal is to get as close to 10,000ms CPU time without going too far over. Once you're okay with the iteration count, you need to run the code many times. For answers here on SFSE, I usually do it at least 5 times and average the results. If I'm seriously invested, I would write a Batchable class that would run say, 100 times, then email me the results.

Aside from that, if you're reading the logs, remember to set a very low logging level. I usually use System.debug(LoggingLevel.ERROR), then set the TraceFlag to match, and setting everything else to the lowest possible level (mostly NONE). Turning down the Apex level to the lowest possible setting helps even out the playing field for methods that may have more lines of code or more heap allocations.

Of course, you could just make a VF page or Lightning Component to just return the values, which I've done before to get a feel for things without needing to read logs, in which case, you can turn logging off entirely. This gives you the best idea of performance without logging interfering.

That said, however, if you need to use DML, SOQL, or SOSL, remember that the first operation in a while will always be the slowest, and get faster. You should "dummy" out the actual queries/DML and use static values when profiling changes. The database uses caching and can be really finicky, and the Limits.getCPUTime() method isn't very accurate, either. Of course, if you do use Limits.getCPUTime(), running more iterations can help give relative ideas of performance.