Ch 3: Benchmarking

29 Oct 2022

Some content on this page is summarized from Advanced Apex Programming, fifth edition, by Dan Appleman. It is insightful and well-written. I highly recommend it. Some code on this page is modified from the sample code for that book. That code is © Dan Appleman, 2021.

Types of Limits

Advanced Apex Programming lists the following types of limits on the Salesforce platform. With careful design, developers can tradeoff one limit against another to avoid problems.

SOQL Queries - mitigate by:
- Always using bulk syntax
- Using before-triggers instead of after-triggers
- Caching query results if possible
- Including fields from related objects in a single query
- Salesforce help documentation mentions using Limits.getLimitDMLRows() and Limits.getQueries()
CPU Time Limits - mitigate by:
- Moving your code to an asynchronous operation
- Moving your code into batch apex
- Optimizing your code - examples are included throughout Advanced Apex Programming
Platform Cache - more about performance than limits.
- Two types: platform cache and session cache.
- Platform cache can become important for the CPU Time limit
- Better utilization of the platform cache means that overall performance of your applications will improve, as will the user experience.
DML Limits - mitigate by:
- Combining DML operations on each object type into a single bulk DML operation
- Perform all DML operations at once as the last part of your program
Heap Size - mitigate by:
- Only query fields you actually need when running SOQL queries
- Instead of storing objects in a static variable, store Object IDs, then requery when needed
Callouts - callouts to external web services. There is a limit on callouts in a given execution context.
API Limits - API entry points allow outside applications to call in to your code. Limited in each 24-hour period. Mitigate by:
- Always supporting bulk operations for every API call.
- Specifying a limit to the amount of data in each call
Email Limits - mitigate by:
- Specifying destination using their UserID, not their email address. These emails are not subject to limits.
Hourly and Daily Limits - several types that deal with max number of operations, but the most important is the asynchronous operation limit, which is the larger of 250,000 or 200 times number of licenses, per 24-hour period. Applies to batch Apex, future methods, queueable Apex, scheduled Apex. Mitigate by:
- Grouping multiple operations into a single asynchronous operation if possible
- Use OrgLimit and OrgLimits classes to get info on the available limits on an org and the current usage
Query Selectivity - only important for objects that have more than 200,000 records in the database. Mitigate by:
- Considering query selectivity during your design
- Viewing the “query plan” feature in the Debug Console’s preferences dialog
Other Platform Limits - see the Apex language reference and Salesforce Developer Limits and Allocations documents for more info.

The rest of this page focuses on ways of benchmarking item 2, above, CPU Time Limits.

CPU Time Benchmarking

To use the code below, first configure the debug options to the lowest level of capture except Apex code, which should be set to “Error.” This is because printing debug logging itself consumes lots of CPU time. For example, consider defining a log level of “Benchmarking” and then remember to reset it back whenever reopening the Developer Console.

Next, define the class Benchmarking with the snippet below.

@istest
public class Benchmarking {
    
    private static Integer referenceStartTime;
    private static Integer referenceEndTime;
    private static Integer targetStartTime;
    private static Integer targetEndTime;

    private static void markReferenceStartTime()
    {
        referenceStartTime = Limits.getCpuTime();
    }

    private static void markReferenceEndTime()
    {
        referenceEndTime = Limits.getCpuTime();
    }

    private static void markTargetStartTime()
    {
        targetStartTime = Limits.getCpuTime();
    }

    // Also called by reportResults - so this doesn't have to be called explicitely
    private static void markTargetEndTime()
    {
        targetEndTime = Limits.getCpuTime();
    }


    private static void reportResults(Integer loops)
    {
        if(targetEndTime==null) markTargetEndTime();
        Integer referenceDuration = referenceEndTime - referenceStartTime;
        Integer targetDuration = targetEndTime - targetStartTime;
        Integer benchmarkResults = targetDuration - referenceDuration;
        // Time in microseconds is duration * 1000 / loops
        Decimal eachItem = benchmarkResults * 1000;
        eachItem /= loops;
        eachItem.setScale(2);
        system.debug(LoggingLevel.Error, 
                     'Reference Duration: ' + referenceDuration + 
                     ' Target duration: ' + targetDuration + 
                     ' Benchmark Results: ' + benchmarkResults + 
                     'ms or ' + eachItem + ' us per operation');
    }
}

Then, add whatever function you want to benchmark to this class, and run the test.

Example 1

For example, the code below tests adding to an integer number. Each increment took on average 0.273 microseconds.

// Benchmark a simple integer increment
@istest
public static void primitiveTests()
{
    Integer v = 0;
    markReferenceStartTime();
    for(Integer x = 0; x<1000000; x++) {}
    markReferenceEndTime();
    markTargetStartTime();
    for(Integer x = 0; x<1000000; x++)
    {
        v += 5;
    }
    reportResults(1000000);
}

Example 2

Another example: calling an empty function call, shown below, took on average 4.944 microseconds.

// Benchmark a call to an empty function
@istest
public static void testFunctionCall()
{
    markReferenceStartTime();
    for(Integer x = 0; x<1000000; x++)
    {
    }
    markReferenceEndTime();
    markTargetStartTime();
    for(Integer x = 0; x<1000000; x++)
    {
        emptyFunction();
    }
    reportResults(1000000);
}
private static void emptyFunction(){}

Example 3

Allocating an array with one element: 4.804 microseconds.

// Benchmark allocation of an array with one element
@istest
public static void testNewAllocate()
{
    List<List<Integer>> numbers = new List<List<Integer>>();
    List<Integer> emptyList = new List<Integer>();
    markReferenceStartTime();
    for(Integer x = 0; x<1000000; x++)
    {
        numbers.add(emptyList); // Add existing list (no allocation)
    }
    markReferenceEndTime();
    markTargetStartTime();
    for(Integer x = 0; x<1000000; x++)
    {
        numbers.add(new List<Integer>{x});  // Add a new list
    }
    reportResults(1000000);
}

Example 4

getGlobalDescribe first operation and cached operations: 35 milliseconds and 6.145 milliseconds, respectively, due to the function’s internal caching according to Advanced Apex Programming.

// Benchmark the getGlobalDescribe first operation and cached operations
@istest
public static void testGlobalDescribe()
{
    markReferenceStartTime();
    for(Integer x = 0; x<1; x++)
    {
        Map<String, Schema.SObjectType> describeInfo = Schema.getGlobalDescribe();
    }
    markReferenceEndTime();
    // Because it was already called once, the following will measure the internal cacheing
    markTargetStartTime();
    for(Integer x = 0; x<1000; x++)
    {
        Map<String, Schema.SObjectType> describeInfo = Schema.getGlobalDescribe();
    }
    reportResults(1000);
}

Example 5

Static field reference (1207 milliseconds total or 6.035 microseconds each) versus dynamic field reference (1913 milliseconds total or 9.565 microseconds each).

// Compare a reference to a static field (setting the value) to a simple variable
@istest
public static void testStaticFieldAccess()
{
    List<Lead> leads = new List<Lead>();
    for(Integer x = 0; x<200; x++)
    {
        leads.add(new Lead(FirstName = 'a'+ string.valueOf(x) + 'name', 
                           LastName = 'b'+ string.valueOf(x) + 'name'));
    }
    String dummyString = '';
    Decimal dummydec;
    markReferenceStartTime();
    for(Integer iteration = 0; iteration<100; iteration++)
    {
        String i = string.valueOf(iteration) + '-';
        for(Integer x = 0; x<200; x++)
        {
            // Access lead field 10 times
            Lead ld = leads[x];
            String v = i + string.ValueOf(x);   // String that varies
            dummyString = dummyString + v;    // Field accessed twice
            dummyString = dummyString + v;  // Field accessed twice
            dummydec = 50;
            dummyString = 'place' + v;
            dummyString = 'company' + v;
            dummyString = 'duns' + v;
            dummyString = 'test lead';
            dummyString = 'email' + v + '@email.com';
        }
    }
    markReferenceEndTime();
    markTargetStartTime();
    for(Integer iteration = 0; iteration<100; iteration++)
    {
        String i = string.valueOf(iteration) + '-';
        for(Integer x = 0; x<200; x++)
        {
            // Access lead field 10 times
            Lead ld = leads[x];
            String v = i + string.ValueOf(x);   // String that varies
            ld.FirstName = ld.FirstName + v;    // Field accessed twice
            ld.LastName = ld.LastName + v;  // Field accessed twice
            ld.AnnualRevenue = 50;
            ld.City = 'place' + v;
            ld.Company = 'company' + v;
            ld.CompanyDunsNumber = 'duns' + v;
            ld.Description = 'test lead';
            ld.Email = 'email' + v + '@email.com';
        }
    }

    // Total fields is about 200 x 100 x 10 = 200,000 field accesses
    reportResults(200000);
}

// Compare a reference to a dynamic field (setting the value) to a simple variable
@istest
public static void testDynamicFieldAccess()
{
    List<Lead> leads = new List<Lead>();
    for(Integer x = 0; x<200; x++)
    {
        leads.add(new Lead(FirstName = 'a'+ string.valueOf(x) + 'name',
                           LastName = 'b'+ string.valueOf(x) + 'name'));
    }
    String dummyString = '';
    Decimal dummydec;
    markReferenceStartTime();
    for(Integer iteration = 0; iteration<100; iteration++)
    {
        String i = string.valueOf(iteration) + '-';
        for(Integer x = 0; x<200; x++)
        {
            // Access lead field 10 times
            Lead ld = leads[x];
            String v = i + string.ValueOf(x);   // String that varies
            dummyString = dummyString + v;    // Field accessed twice
            dummyString = dummyString + v;  // Field accessed twice
            dummydec = 50;
            dummyString = 'place' + v;
            dummyString = 'company' + v;
            dummyString = 'duns' + v;
            dummyString = 'test lead';
            dummyString = 'email' + v + '@email.com';
        }
    }
    markReferenceEndTime();
    markTargetStartTime();
    for(Integer iteration = 0; iteration<100; iteration++)
    {
        String i = string.valueOf(iteration) + '-';
        for(Integer x = 0; x<200; x++)
        {
            // Access lead field 10 times
            Lead ld = leads[x];
            String v = i + string.ValueOf(x);   // String that varies
            ld.put('FirstName', (string)ld.get('FirstName') + v);    // Field accessed twice
            ld.put('LastName', (string)ld.get('LastName') +  v);  // Field accessed twice
            ld.put('AnnualRevenue', 50);
            ld.put('City','place' + v);
            ld.put('Company','company' + v);
            ld.put('CompanyDunsNumber', 'duns' + v);
            ld.put('Description', 'test lead');
            ld.put('Email', 'email' + v + '@email.com');
        }
    }        
    // Total fields is about 200 x 100 x 10 = 200,000 field accesses
    reportResults(200000);
}

Example 6

Results:

Dynamic field, test against each entry: 38.25 microseconds each
Static field reference, endsWithIgnoreCase: 17.59 microseconds each
Temporary variable and endsWithIgnoreCase: 14.23 microseconds each
Temporary variable and convert to lower case explicitly: 15.4 microseconds each
Temporary variable and a set lookup: 2.22 microseconds each

private static Set<String> spamList = new Set<String>{'@yahoo.com','@gmail.com',
    '@hotmail.com','@whitehouse.gov','@test.com','@nobody.com',
    '@abc.com','@spam.com','@xyz.com','@ignoreme.com'};

private static Set<String> spamDomainsList = new Set<String>{'yahoo.com','gmail.com', 
    'hotmail.com', 'whitehouse.gov','test.com','nobody.com',
    'abc.com','spam.com','xyz.com','ignoreme.com'};


// Dynamic field, test against each entry
private static List<Lead> checkForSpam1(List<Lead> leads, String emailField)
{
    List<Lead> results = new List<Lead>();
    for(Lead ld: leads)
    {
        for(string spamDomain: spamList)
            if(ld.get(emailField)!=null && 
               ((String)ld.get(emailField)).endsWithIgnoreCase(spamDomain)) 
               results.add(ld);
    }
    return results;
}

// Use a static field reference and endsWithIgnoreCase
private static List<Lead> checkForSpam2(List<Lead> leads, String emailField)
{
    List<Lead> results = new List<Lead>();
    for(Lead ld: leads)
    {
        switch on emailField
        {
            when 'email' {
                for(string spamDomain: spamList)
                    if(ld.email!=null && ld.email.endsWithIgnoreCase(spamDomain)) 
                    results.add(ld);
            }
            when else {
                for(string spamDomain: spamList)
                    if(ld.get(emailField)!=null && 
                       ((String)ld.get(emailField)).endsWithIgnoreCase(spamDomain)) 
                       results.add(ld);
            }
        }
    }
    return results;
}

// Use a temporary variable and endsWithIgnoreCase
private static List<Lead> checkForSpam3(List<Lead> leads, String emailField)
{
    List<Lead> results = new List<Lead>();
    Boolean useStaticEmail = (emailField=='email');
    for(Lead ld: leads)
    {
        String email = (useStaticEmail)? ld.email: (String)ld.get(emailField);
        if(email!=null)
        {
            for(string spamDomain: spamList)
                if(email.endsWithIgnoreCase(spamDomain)) results.add(ld);
        }
    }
    return results;
}

// Use a temporary variable and convert to lower case explicitly
private static List<Lead> checkForSpam4(List<Lead> leads, String emailField)
{
    List<Lead> results = new List<Lead>();
    Boolean useStaticEmail = (emailField=='email');
    for(Lead ld: leads)
    {
        String email = (useStaticEmail)? ld.email: (String)ld.get(emailField);
        if(email!=null)
        {
            email = email.toLowerCase();
            for(string spamDomain: spamList)
                if(email.endsWith(spamDomain)) results.add(ld);
        }
    }
    return results;
}

// Use a temporary variable and a set lookup
private static List<Lead> checkForSpam5(List<Lead> leads, String emailField)
{
    List<Lead> results = new List<Lead>();
    Boolean useStaticEmail = (emailField=='email');
    for(Lead ld: leads)
    {
        String email = (useStaticEmail)? ld.email: (String)ld.get(emailField);
        String emaildomain = email?.substringafter('@')?.toLowerCase();
        if(emaildomain!=null)
        {
            if(spamDomainsList.contains(emaildomain)) results.add(ld);
        }
        /*
            I could have used the same spamList set as the other functions 
            and the following code to extract the domain:
            String emaildomain = email?.substring(email?.indexof('@'))?.toLowerCase();
            But it parses the string twice, and is thus somewhat slower
        */
    }
    return results;
}


@istest
public static void testCheckForSpam()
{
    List<Lead> leads = new List<Lead>();
    for(Integer x = 0; x<10000; x++) leads.add(new Lead(LastName ='test', 
                                                        Email = 'someone@myemail.com'));
    markReferenceStartTime(); // Reference time not important for these tests
    markReferenceEndTime();
    markTargetStartTime();
    checkForSpam1(leads, 'email');
    markTargetEndTime();
    system.debug(logginglevel.error, 'Dynamic field, test against each entry');
    reportResults(100000);
    markTargetStartTime();
    checkForSpam2(leads, 'email');
    markTargetEndTime();    // Must be explicit to override previous value
    system.debug(logginglevel.error, 'Target uses static field reference');
    reportResults(100000);
    markTargetStartTime();
    checkForSpam3(leads, 'email');
    markTargetEndTime();    // Must be explicit to override previous value
    system.debug(logginglevel.error, 'Target uses temporary variables');
    reportResults(100000);
    markTargetStartTime();
    checkForSpam4(leads, 'email');
    markTargetEndTime();    // Must be explicit to override previous value
    system.debug(logginglevel.error, 
    'Target uses temp variables and explicit lower case conversion');
    reportResults(100000);
    markTargetStartTime();
    checkForSpam5(leads, 'email');
    markTargetEndTime();    // Must be explicit to override previous value
    system.debug(logginglevel.error, 'Target uses temp variables and set lookup');
    reportResults(100000);

}