Benchmarking Code
With a small amount of code you can do some testing to figure out what is eating up that precious CPU limit. (Check out How does SF calculate the CPU time? for reference on what Salesforce counts towards this limit.)
To help get started, I would recommend installing the LimitsProfiler package that Adrian Larson has developed. By using the code provided in this unmanaged package, you no longer need to deal with setting the appropriate logging levels when debugging. In fact, you don’t need to use debug logs at all. (Note that this unmanaged package contains several classes, pages, a custom object, and a custom settings object, and should never be installed into a production environment.)
Next, create a class that extends LimitsProfiler. The implementation below contains code to benchmark static versus dynamic variable assignment.
public with sharing class LimitsTesting {
public class AssignmentProfiler extends LimitsProfiler {
Contact ct;
ID sourceid;
ID actid;
public override void setup() {
// Query a contact - change this to something that will find a match in your org
ct = [SELECT ID, AccountID FROM Contact WHERE LastName LIKE 'testcontact%' LIMIT 1];
sourceid = ct.AccountID;
}
public override void execute() {
// Test #1: Put what you are measuring in here, for example:
actid = sourceid;
// Test #2: Keep test #1 uncommented. After you get your baseline measurements, uncomment this block to add in ten more and test again:
/*
actid = sourceid;
actid = sourceid;
actid = sourceid;
actid = sourceid;
actid = sourceid;
actid = sourceid;
actid = sourceid;
actid = sourceid;
actid = sourceid;
actid = sourceid;
*/
// Test #3: Comment out test #2 and test a static field assignment:
/*
actid = ct.AccountID;
actid = ct.AccountID;
actid = ct.AccountID;
actid = ct.AccountID;
actid = ct.AccountID;
actid = ct.AccountID;
actid = ct.AccountID;
actid = ct.AccountID;
actid = ct.AccountID;
actid = ct.AccountID;
*/
// Test #4: Comment out tests #2 and #3, adjust the loop iteration to 100000, and test a dynamic apex assignment:
/*
actid = (Id)ct.get('AccountID');
actid = (Id)ct.get('AccountID');
actid = (Id)ct.get('AccountID');
actid = (Id)ct.get('AccountID');
actid = (Id)ct.get('AccountID');
actid = (Id)ct.get('AccountID');
actid = (Id)ct.get('AccountID');
actid = (Id)ct.get('AccountID');
actid = (Id)ct.get('AccountID');
actid = (Id)ct.get('AccountID');
*/
}
}
}
After saving the class, navigate to /apex/LimitsProfiler and click the "Configure" button to configure a new test run. The Profiler Type should be set to LimitsTesting.AssignmentProfiler and Iterations should be set to 1,000,000. Only the Display CPU Time? checkbox needs to be checked. Saving the configuration will take you back to the main page.
From the main page, take five or more measurements and then calculate the average CPU time across the tests. Record the calculated average, and if you wish, save your results. (Saving the results stores them in a custom object that you can reference in a report later, if you need them.)
You will then perform three more tests, following the directions in the comments of the above class. (For the fourth test, you will likely need to drop the number of iterations down to 100,000 or 10,000.) When calculating the CPU time for tests #2-4, remember to subtract the average CPU time from the first test. We subtract this number when calculating the results of the other tests because we want to know the CPU time for a single variable assignment, not the CPU time for a variable assignment in a for loop.
Benchmarking Results
Test #1: 1,000,000 iterations - 1 variable assignment (baseline test)
939ms average CPU time
Test #2: 1,000,000 iterations - baseline test + 10 variable assignments
2852ms average CPU time
2852-939ms = 1913ms / 10 assignments = 191.3ms / 1,000,000 iterations = .19 microseconds per assignment
Test #3: 1,000,000 iterations - baseline test + 10 static field assignments
9167ms average CPU time
9167-939ms = 8228ms / 10 assignments = 822.8ms / 1,000,000 iterations = .8 microseconds per assignment
Test #4: 100,000 iterations - baseline test + 10 dynamic field assignments
8547ms average CPU time
8547-93.9ms = 8453.1ms / 10 assignments = 845.31ms / 100,000 iterations = 8.5 microseconds per assignment
Note: We should only subtract 93.9ms from the average in test #4 since we are only performing 100,000 instead of 1,000,000 iterations.
What if I don't want to install an unmanaged package to benchmark CPU time?
More details around benchmarking Apex can be found in the DF16 presentation: The Dark Art of CPU Benchmarking and examples found on my DF16 Github repo. The BenchmarkTests.cls class can be used as a guide if you wish to perform CPU benchmarking without using the LimitsProfiler. One of the most important things to remember when benchmarking CPU time is to make sure that all of your logging levels are turned off except where absolutely necessary.
What are the most CPU intensive operations?
We learned a lot when preparing for our DF ‘16 talk on benchmarking. Here are some of the highlights from what we’ve discovered:
Calling Schema.getGlobalDescribe() is a big one. While Salesforce does its own caching, it actually isn't very good at caching. Calling Schema.getGlobalDescribe() eats up precious milliseconds of CPU time even on subsequent calls.
Using doubles instead of decimals is 200 times faster (half a microsecond vs 100 microseconds) - though make sure you understand the difference when choosing one or the other (Decimal or double?)
Serializing data can be CPU intensive depending on the amount of data being serialized.
Dynamic assignment uses 8+ microseconds of CPU time, whereas a simple assignment or static assignment can be done in far less than a microsecond. Again, this is really only going to be an issue if you’re iterating over a large list.
List<Account> account = [SELECT Id FROM Account WHERE Id = '001someidhere'];
if (account.size() == 0) return;
Id accountId = account[0].Id;
for (Contact contact : contacts) {
contact.AccountId = accountId; // Do this
contact.AccountId = (Id)account[0].get('Id'); // Avoid doing this
}
What else am I missing here? What else should we avoid?
