Apex CPU Time limit in Batch start() - is this a Query Timeout and how to cope with?

Question

I have a Batch iterating over a large amount of records (with many fields) and 2 of their related child records. The start() method uses Dynamic SOQL to fetch them via QueryLocator to vary which fields are queried.

global Database.QueryLocator start(Database.batchableContext context) {

    programTypeFacade.setRunningBatch(context.getJobId());

    String soql = Utils.getSelectXFrom('Volume__c');

    String relationSubQueries = ', (SELECT num_Volume_01__c, num_Volume_02__c, num_Volume_03__c, chk_LockVolume_03__c ' +
                                '   FROM VolumeSchedules__r)' +
                                ', (SELECT mdr_Volume__c, lkp_VolumeData__r.txt_Mnemonic_1__c, lkp_VolumeData__r.pkl_Status__c, lkp_VolumeData__r.' + String.join(programTypeFacade.relevantAttributeFields,', lkp_VolumeData__r.') +
                                '   FROM VolumeDataLinks__r)'; 

    soql = soql.replace('FROM', relationSubQueries + ' FROM');
    soql += ' WHERE mdr_ProgramType__c = \'' + programTypeFacade.Id + '\'';

    return Database.getQueryLocator(soql);
}

and this is the Batch Apex log output

SELECT ...FROM Volume__c  
16:57:12.863 (863677615)|SOQL_EXECUTE_END|[44]|Rows:21357 
17:01:28.956 (256956271398)|SYSTEM_METHOD_EXIT|[33]|LIST<UP2GO_2F__Volume__c>.size()   
17:01:28.956 (256956299794)|SYSTEM_METHOD_EXIT|[48]|Database.QueryLocatorIterator.hasNext()    
17:01:28.956 (256956366758)|SYSTEM_METHOD_ENTRY|[33]|LIST<UP2GO_2F__Volume__c>.size()    
17:01:28.956 (256956378599)|SYSTEM_METHOD_EXIT|[33]|LIST<UP2GO_2F__Volume__c>.size()

...(hundreds of equal lines...

17:03:43.785 (391785456348)|SYSTEM_METHOD_EXIT|[38]|LIST<UP2GO_2F__Volume__c>.size()    
17:03:43.785 (391785470977)|SYSTEM_METHOD_ENTRY|[39]|Database.QueryLocator.querymore(Integer)    
17:03:43.973 (391973215599)|EXCEPTION_THROWN|[39]|System.LimitException: Apex CPU time limit exceeded

Is this like a Query Timeout? Can I prevent this and how?

EDIT: This must be a bug a the query result is really small: 32.000 records with max. 200 child records. If I run the same query in the console the result comes back in a second without any problems.

Answer 1

I suggest querying the child records in the execute method instead. This should speed up the start() method significantly. And it should solve the cpu time limit problem as well.

public Database.QueryLocator start(Database.batchableContext context) {
    return Database.getQueryLocator(
        [SELECT Id FROM Foo__c WHERE ... AND ...]
    )
}

public void execute(Database.BatchableContext context, List<Foo__c> rawRecords){
    List<Foo__c> records = [SELECT Field1, Field2, (SELECT FieldA FROM Bar__r) FROM Foo__c WHERE Id IN :rawRecords];

    //do something
}

The second query at the execute() method should also perform much better, as you are querying only a subset of records corresponding to the batch size.

My example is not using dynamic SOQL, but this would work as well.

Answer 2

Behind the scenes, when start() returns, it is handed back to a process that begins the process of breaking the items into the appropriate scope size. The process roughly looks like:

List<List<Object>> objects = new List<List<Object>>();
Object[] temp = new Object[0];
Database.QueryLocator locator = batch.start(context);
Iterator<Object> iterator = locator.iterator();
while(iterator.hasNext()) {
    temp.add(iterator.next());
    if(temp.size()==scopeSize) {
        objects.add(temp);
        temp = new Object[0];
    }
}
// other housekeeping

All you really need to know is that there's code running outside your code that runs with the same rules as normal Apex Code-- it has a CPU limit of 60,000 ms (one minute of code time), after which the process will die.

For simple queries, this is usually more than enough time, but in some cases, your batch process will die before it gets a chance to run (I'd imagine with more complicated queries/larger queries/etc).

There is good news, however. Summer '14 includes an update that will change the limit from 60,000 ms to 600,000 ms (10 minutes), which should make your code fully functional after this weekend's update. Since a fix is forthcoming, I wouldn't try to fix the problem yourself.