Szyny - Czas wykonania dla żądania znacznie wyższego niż czas wyświetlania i DB

Question

Mam kontroler, który zwraca JSON lub XML z dość złożonego zapytania relacyjnego z pewną logiką kontrolera.

Dostroiłem stronę DB, poprawiając moje zapytanie i upewniając się, że moje indeksy są poprawne dla mojego zapytania.

W moim dzienniku widzę rzeczy tak:

Completed in 740ms (View: 1, DB: 50) 

Więc jeśli dobrze rozumiem, oznacza to, że widok trwało 1 sekundę do renderowania i kwerendy DB było 50ms. Czy cały pozostały czas w kontrolerze? Próbowałem ominąć moją logikę kontrolera i zostawiłem tam moje to_json i to_xml i jest to równie powolne. Jako punkt odniesienia mój średni zestaw wyników JSON zwróconych wynosi 168k.

Czy istnieją inne etapy, które wchodzą w zakres Ukończonych w czasie? Czy zawiera czas do ostatniego bajtu na transfer sieci?

Aktualizacja: I zawinięte różne części mojego kontrolera w benchmarkingu bloków:

self.class.benchmark("Active Record Find") do 
    #my query here 
end 

Co znalazłem było to, że mimo iż linia log mówi DB: 50 mój aktywny rekord znalezisko bierze prawie wszystkie z pozostały czas. Więc teraz jestem zdezorientowany co do tego, co oznacza ten numer DB i dlaczego linia testowa ma powiedzieć ~ 600ms, ale DB: czas będzie wynosił ~ 50.

Dzięki

Answer 1

Twój numer DB czas faktycznie spędzony w bazie danych, ale nie ładuje obiektów ActiveRecord.

Więc jeśli ładowanie 168.000 obiektów rubin active_record do renderowania następnie jako JSON, byłoby to wyjaśnić 550 ms (lub więcej!)