Why find("all") took so long to run


#1
 $results = $this - > Task - > find('all', array(
   'contain' => array('EntityValues', 'ContentItems'),
   'conditions' => $conditions,
   'joins' => $joins,
   'order' => $order
 ));

Above function took 30 seconds to run, but I check query logs, and don’t see any slow queries.
log shows: ‘count’ => (int) 15, ‘time’ => (float) 61
so the total is 61 microsecond as my understanding. Any ideas?


#2

Do you use the Debug Kit? With that it should be really easy to find out :slight_smile:


#3

I just added DebugKit.
sql log:
Total Time: 103 ms
Total Queries: 21 queries

But in the timer tab:
I found that “Controller action” took “30145.06ms”. Do you know what that is?

Thanks!


#4

Sounds like some other script in that request could be causing the error. With DebugKit you can add timers throughout the part of the script that’s running to help find out what’s actually slow.

For example, you can place timers around the find call to see if it’s something happening during the find('all') such as building objects or something running in an event.


#5

How many rows does the query fetch? Maybe you or some component are iterating all of it.


#6

I set recursive = -1 in Model, but actually it got reset to 1 because I have two contains in find(). So the solution I figured out was commenting contains, and adding additional “find all” against these two tables after. However, I am not sure why Deep associations (in Dbosource.php) took so long. I didn’t see the slow queries when it did deep associations though. Is it bug?

@raul338, it returns less than 10k records, and the sql execution is about 20 microseconds.