Batch Logging

This article demonstrates some common approaches to batch logging.

Batch jobs are great for processing large amounts of data in the background. They can be scheduled, executed by hand on demand, or via some sort of trigger. The common pain point with these is that there's little visibility when it comes to failures. Hence, many developers turn to logging. There are a number of use cases to cover here: basic error handling, trace logging, and profiling.

Basic Error Handling

Proper error handling is essential to weed out those pesky errors in batch jobs. Often Salesforce will mask failures or provide a one-liner error message with no stack trace. This is where we can make a huge difference by taking matters into our own hands. Below is a code snippet that incorporates error logging in the most troublesome execute() method.

Basic Batch Logging

public class LeadsBatch implements Database.Batchable<sObject>, Database.Stateful {
    private String query ='';
    private Triton logger = Triton.instance;
    
    public LeadsBatch(String leadQuery) {
        this.query = leadQuery;
    }
    
    public Database.QueryLocator start(Database.BatchableContext bc) {
        return Database.getQueryLocator(query);
    }
    
    public void execute(Database.BatchableContext bc, List<Lead> leads) {
        for(Lead l : leads){
            try {
                LeadProcessingResult result = LeadService.getQualificationScore(l);
                if(result.isSuccess) {
                    l.Score__c = result.qualificationScore;
                }
            } catch(Exception e){
                this.logger.addError(TritonTypes.Area.LeadQualification, e);
            }
        }
        
        try {
            update leads;
        } catch(Exception e){
            this.logger.addError(TritonTypes.Area.LeadQualification, e);
        }
    }

    public void finish(Database.BatchableContext bc){
        this.logger.flush();
    }
}

There is a good chance you might find similar batch jobs in your own org. The pattern is quite typical: query records, process them in a loop, then perform a DML, a callout or some other action. Let's now dive into the details of what's happening here.

• Note the use of the Database.Stateful interface in the declaration of our LeadsBatch class. In this example we have made our batch stateful, or, in other words, retain its state between the different iterations of the execute() method. For more information on this please refer to Salesforce developer documentation here. The reason we need state preservation is to be able to accumulate our logs in a buffer within the logger class variable declared on line (3). Static context in our Singleton logger instance will not be preserved between different batch iterations.
• In this batch class we're utilizing another concept called bulk logging introduced in this section. You'll notice the use of the addError() method instead of the error() method as in the previous example. The addError() method appends to the log buffer that is subsequently flushed in the finish() method on line (33).

The main motivation behind buffering logs is to preserve platform event (PE) allocations by emitting a single platform event containing a collection of logs. Since we're dealing with a batch, it may take hundreds of iterations to complete. Assuming we log something on every iteration, quite a few PE allocations may be consumed.

• The use of the finish() method on line (33). This method runs when a batch is finished executing, regardless of whether those executions resulted in exceptions. This is good news for us as it ensures that our log buffer is persisted properly.

• Note the use of the Area enum on line (21) and (28) in the catch() clause. The more accurate you can be with this value, the better your searching and reporting experience will be.

It is possible to log within all methods of the batch class, not just the execute(). In fact, it is highly recommended you do so when you have logic in those methods. In our example above there is really not much going there, hence no logging needed.

Grouping Logs From Multiple Iterations

Let's now incorporate the idea of uniting logs under a single transaction illustrated in the very first example with the concept of bulk logging. We'd like to see all logs for each of the iteration grouped under the same parent, and we are also going to do in a way that is consistent with the platform best practices by emitting only a single platform event. The example below also adds a few debug() and event() statements to the mix for a more detailed trace of batch execution:

Batch + Transaction

public class LeadsBatch implements Database.Batchable<sObject>, Database.Stateful {
    private String query ='';
    private Log logger = Triton.instance;
    //will need to keep track of the number of iterations
    private Integer iteration = 0;
    
    public LeadsBatch(String leadQuery) {
        this.query = leadQuery;
        logger.startTransaction();
        logger.addDebug(TritonTypes.Type.LeadsBatch, 
                        TritonTypes.Area.LeadQualification,
                        'LeadsBatch initialized',
                        'LeadsBatch initialized with query: ' + query );
    }
    
    public Database.QueryLocator start(Database.BatchableContext bc) {
        logger.addEvent(TritonTypes.Level.FINE,
                    TritonTypes.Type.LeadsBatch, 
                    TritonTypes.Area.LeadQualification,
                    'LeadsBatch starting',
                    'Fetching query locator for query: ' + query );
        return Database.getQueryLocator(query);
    }
    
    public void execute(Database.BatchableContext bc, List<Lead> leads) {
        iteration++;
        logger.addEvent(TritonTypes.Level.FINE,
                    TritonTypes.Type.LeadsBatch, 
                    TritonTypes.Area.LeadQualification,
                    'LeadsBatch executing iteration: '+ iteration,
                    'Processing ' + leads.size()) + ' in this iteration';
        for(Lead l : leads) {
            try {
                LeadProcessingResult result = LeadService.getQualificationScore(l);
                if(result.isSuccess) {
                    l.Score__c = result.qualificationScore;
                } else {
                    logger.addEvent(TritonTypes.Level.FINE,
                                    TritonTypes.Type.LeadsBatch, 
                                    TritonTypes.Area.LeadQualification,
                                    'LeadsBatch failed to obtain successful qualification score',
                                    'Result returned for lead id ' + l.Id + 
                                        Triton.SPACE_SEP + 'Result: ' + 
                                        Triton.SPACE_SEP + String.valueOf(result);
                }
            } catch(Exception e){
                logger.addError(TritonTypes.Area.LeadQualification, e);
            }
        }
        
        try {
            update leads;
        } catch(Exception e){
            logger.addError(TritonTypes.Area.LeadQualification, e);
        }
    }

    public void finish(Database.BatchableContext bc){
        logger.addDebug(TritonTypes.Type.LeadsBatch, 
                        TritonTypes.Area.LeadQualification,
                        'LeadsBatch finishing',
                        'Iterations processed: ' + iteration);
        logger.flush();
        logger.stopTransaction();
    }
}

For the most part this example is similar in spirit to the basic batch logging snippet. A few things to highlight here nonetheless:

• Note the more generous logging statements that are incorporated into every method of this batch class. This will provide more details when analyzing the execution and help examine some key data points such as iteration number and the query that was used to construct a query locator.

• In this example we're making use of the different log levels (see Level enum). The constructor and the finish() methods are utilizing the DEBUG level, whereas the start() and execute() methods are logging at INFO level.

The general rule of thumb with log levels is to log anything that is essential for troubleshooting at DEBUG, WARNING or INFO levels. Everything else that may be helpful should remain at the FINE level or below.

Errors are typically always logged at the highest level of ERROR.

• Last but not least is that all these logs that we're generating here will be grouped under a single parent log. This is quite convenient for future troubleshooting needs as there is now an nice easy to navigate structure available.