25

We're experiencing a very annoying issue with a Batch job processing "Large Data Volume" (1.5M records over a table containing 4.5M records). Our batch start method last statement is: return Database.getQueryLocator(soql); and despite the query completes successfully returning 1.5M rows, the batch doesn't kick off and a CPU timeout error is reported.

I believe the CPU timeout is not to be attributed to any of our logic, being the query our last code statement and completing it successfully (look at the pseudo-code, debug log and screenshots of CPU timeline and Apex Jobs provided below). I have the strong suspect the issue is related to the "housekeeping" sfdcfox mentions in here - but that's just a weak suspect as if that'd be the case I suppose I wouldn't be the only one experiencing the issue.

We have optimized the SOQL so that only the Id field of targeted records is selected: the SOQL doesn't contain any child/sub-query, and the records returned by the SOQL are as lightweight as they can be being only their ID field selected. This is a known factor that affects badly batch start() methods with CPU timeouts, but it's not to be considered by us after optimization. I wonder then if there are others.

The question (and bounty) is out for a clear, documented, detailed answer to the question: what are factors that can affect/impact on the post-processing that SFDC does on the recordset which is returned by a batch start() method, other than the presence of child queries or parent records?

Pseudo code that gives an idea of my batch

global with sharing class APseudoBatch {

  private String soqlString = 'SELECT alias.Id FROM MyObject__c alias WHERE ...';

  global Database.QueryLocator start (Database.BatchableContext BC) {

    MyOtherObject__c[] prevBatchData = [SELECT Id FROM MyOtherObject__c WHERE ...];

    delete prevBatchData;

    return Database.getQueryLocator(soqlString);

  }

  (...)

}

Debug log

34.0 APEX_CODE,DEBUG;APEX_PROFILING,INFO;CALLOUT,INFO;DB,INFO;SYSTEM,DEBUG;VALIDATION,INFO;VISUALFORCE,INFO;WORKFLOW,INFO

05:12:19.152 (152753319)|SOQL_EXECUTE_BEGIN|[159]|Aggregations:0|SELECT id FROM AAA__c

05:12:19.152 (158857573)|SOQL_EXECUTE_END|[159]|Rows:0

05:12:19.152 (163217923)|SOQL_EXECUTE_BEGIN|[165]|Aggregations:0|SELECT id FROM BBB__c

05:12:19.152 (167389830)|SOQL_EXECUTE_END|[165]|Rows:1

05:12:19.152 (167994190)|DML_BEGIN|[405]|Op:Delete|Type:BBB__c|Rows:1

05:12:19.152 (401425184)|DML_END|[405]

05:12:19.152 (402249359)|SOQL_EXECUTE_BEGIN|[172]|Aggregations:0|SELECT id FROM CCC__c

05:12:19.152 (406737724)|SOQL_EXECUTE_END|[172]|Rows:4

05:12:19.152 (407218557)|DML_BEGIN|[405]|Op:Delete|Type:CCC__c|Rows:4

05:12:21.104 (2104679115)|DML_END|[405]

05:12:21.104 (2110622491)|DML_BEGIN|[409]|Op:Upsert|Type:DDD__c|Rows:4

05:12:21.104 (2183712913)|DML_END|[409]

05:12:21.104 (2192886624)|SOQL_EXECUTE_BEGIN|[188]|Aggregations:0|Select s.Id From LDV__c

05:13:25.773 (66773435973)|SOQL_EXECUTE_END|[188]|Rows:1517052

(Line 188 is the last line of my start() method - the debug log ends there, I've pasted it all as it is)

Screenshot of Apex Jobs page

Failed batch line from Apex Jobs page

The SOQL completes successfully at 05:13:25, the Batch Job is marked failed at 05:16 in the Apex Jobs page. Strange, isn't?

Screenshot of Execution Timeline

timeline from dev console

LAST UPDATE

Changed the batch query removing all the WHERE criterias. The behavior of the CPU timeout changed - now it is happening 10 minutes after the SOQL failure (as the linked sfdcfox post suggests) instead of 2-3 minutes as per my previous debug logs. The table contains 3.5M records now.

  • 2
    Please post the rest of the code in your start method. Asking if anyone else is experiencing the same problem leads to an opinion based discussion rather than one based on facts. If you have data to post from Dev Console for the Execution Timeline, I'm confident that would be helpful as well. – crmprogdev Jun 13 '16 at 13:22
  • 5
    You should put the delete in a separate batch and use batch chaining instead. – Adrian Larson Jun 13 '16 at 17:02
  • 2
    Just throwing an idea.. Try limiting the records in the query and return them (Hit & Try), let me know the outcome..if this works then you can use schedular class to call this batch class and acheive the functionality – Krishna Bidwai Jun 13 '16 at 17:26
  • 4
    You can separate it in to two batches and execute the second batch from the finish method of first batch. In the second batch , query the the results which are not retrieved in first batch. This way you can reduce the timeout error. Just an idea – Anurag A Jun 15 '16 at 13:57
  • 4
    @MLucci I think you're missing the point of the suggestions. You first need to get your batch method working and can then add things back in to see where, what & why it's breaking! It could be that something that's not being reported is causing it to break. You won't be able to see that until you eliminate these other things and can get something to actually work. Once you can, you can increase record limits, add where clauses, etc to see what it is that causes your batch code to break. – crmprogdev Jun 16 '16 at 14:26
1

Every time you ask for a data from salesforce, everytime you have to call the salesforce servers. Now each server call limit is 10,000 millisecond = 10 seconds, that means if server call is taking more than 10 seconds to return results your batch will immediately fail with status "CPU time exceeds".Each server call can be querying data, Executing codes or others.

I feel, in your case your start method works fine as there are no failure during fetching data (that is why your SOQL completes at some time and finally after few minutes your batch is getting failed). Even If you know, you may find different debug logs for start method, each batch and finish method. Suppose you have 5 batches then you may get 7 debug logs for your batch class (1 for Start,5 for execute and 1 for finish). If you are getting your very first debug without error that means your start method is fine.

I feel, the CPU limit reach is hitting from execute method somewhere. As you specified that batch fails after few minutes of SOQL execution.

Possibility for failure:

  1. may be using heavy subquery (another query in your execute method)
  2. may be using for loop inside a for loop
  3. may be very lengthy code in execute method

Solution:

  1. You can use a subquery but make sure it is optimized and return data rapidly OR You can always make you class stateful and instead of writing a subquery, write the same query inside your start method and gather data in a map to be used further.
  2. try eliminating nested for loops as they are the main eaters of CPU time to process the whole execute code within 10 seconds. Make two different loops out of nested one, Use collections to store data results temporarily gained from first loop then feed it to another loop to get the outcome.
  3. If your logic is lengthy, go for splitting batch into multiple batches. Process data according to your half logic, store it in collections like map, place your another half logic in another batch, call the batch from the finish method with the temporary collection as input.
0

Reason for CPU time out (in my case) – SubQuery

I tried SOQL Query Plan and run same query in Developer console and workbench, but it was not timing out. Still, gave one shot to idea that I had and tried to remove subquery from start method and queried again in execute method. And voilla…. it worked. So, subquery in SOQL was causing CPU time limit error and it was not even able to enter in execute method. I got lost because there were no debug logs. Instead of spending time on actual issue, I spent lot of time to figure out why debug log is not showing up.

Lessons learned

If we are getting CPU time limit error (in my experience I have seen many), then avoid using sub-query, its costly and time consuming. Damn !!! I need to tell my colleagues of previous projects to check code for subquery, where they are getting CPU error. If batch apex error says “First error – some error” , that means error is in start method and don’t even try to hunt for execute method debug logs.

This is just a shot at your CPU timeout issue on Start method of batch.

This could be helpful: Batch Apex – First error: Apex CPU time limit exceeded

0

Checking all the answers & comments what I can tell is:

  • Have you tried removing the delete from the start method of the batch and put it on a separate batch and use batch chaining? (as @Adrian Larson has suggested on comments)

  • To my opinion you don't have to remove the Where clause on SOQL query. What you can avoid from query are Subqueries (in case you use them on the start method) as others have suggested. During my experience I've had the same error and by removing the Subqueries on the start method and querying the child records on the execute method did solve the issue for me.

P.S. You might have solved the issue already, as it's a 2 years old question. Would be nice if you update this thread by providing the solution of your issue or accepting the correct answer.

Thanks

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.