4

I have a long running batch that is taking days to execute and creates millions of records. To speed it up I used the profiling tools of the Developer Console.

Per batch execute() I see this timeline

enter image description here

and it speaks a clear language. It's neighter the small Apex code nor the SOQL query or DML that is eating up time. It's waiting and doing nothing.

Where does this huge gap come from?

Is this related to the queuing concepts described in the whitepaper "Asynchronous Processing in Force.com - Salesforce.com"?

Improve this question
5
  • 2
    Your profiling settings might not be sufficient, the usual cause. The "queue" bit produces gaps with inter-logging time, not intra-logging time (meaning, each execute might be spaced seconds or even minutes apart, while the log should represent continual execution time). Try turning your logging levels up and see if that gives a better timeline. You might also need to contact Developer Support if indeed there is a stall; it shouldn't happen.
    – sfdcfox
    Aug 14, 2013 at 13:05
  • @sfdcfox: Great can you convert from a comment to an answer? BTW: Are you working for Saleforce? In which role?
    – Robert Sösemann
    Aug 14, 2013 at 13:15
  • @sfdcfox: I changed log levels as show in the updated screenshot above and nothing changed.
    – Robert Sösemann
    Aug 14, 2013 at 13:21
  • 1
    I was a Technical Support/Premier Support agent from 2005 to 2008, and moved on to consulting to better serve salesforce.com clients, and eventually ended up as a full-time developer/admin for a small company, where I am now. Let me build a test scenario and see if I can reproduce. By the way, what server are you on, I'll see if I can reproduce on the same instance.
    – sfdcfox
    Aug 14, 2013 at 14:09
  • It's on NA15, but we see the same behavior everywhere. Just some background details for you test scenario. This is a so called snapshot batch. It backups huge amounts of structured (e.g. 3 related SObjects) data and denormalizes it into a single table with hundreds of fields.
    – Robert Sösemann
    Aug 15, 2013 at 7:06

1 Answer 1

Reset to default
3

The grayed out portion (the gap) is time that Salesforce spends doing stuff that you don't have control over. This could include allocating/freeing memory, waiting for a lock to be removed, initializing a DB connection, etc. Since this is the timeline for the execute method, the methods described in the white-paper for async processing shouldn't apply here.

Is this reproducible every time, or does that gap vary? Since it is a 5 second gap, I would guess that Salesforce is waiting for something. I wouldn't be surprised if it took 5 seconds to wait for records to be unlocked if there is another process going on. It could also depend on the current load of the instance. Running at 3am on Saturday would probably have smaller gaps than running at 10am on a Wednesday.

That timeline is completely generated from the apex log. There have been previous bugs with how the developer console shows the start and end of those gaps. It could be worth it to look at the raw log and see if there is indeed 5 seconds between those two events, and if there are any other event lines in-between.

Improve this answer

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .